Home » Modeling » EMF "Technology" (Ecore Tools, EMFatic, etc) » [CDO] Client registration timeout exception
| [CDO] Client registration timeout exception [message #118189] |
Mon, 14 April 2008 04:07  |
Eclipse User |
|
|
|
Originally posted by: ben.razzledazzle.gmail.com
I'm new to CDO and I'm trying to connect to a CDO server using the "CDO
Sessions View" (org.eclipse.emf.cdo.CDOSession.CDOSessionsView). Here is
rundown of what I'm doing:
- JVM 1.5.0 (using OS X) , Eclipse 3.4m5,
- I run a CDO server using the product configuration
org.eclipse.emf.cdo.server.product.
- I run an eclipse workbench configuration with the following additional
plugins:
org.eclipse.emf.cdo (0.8.0)
org.eclipse.emf.cdo.edit (0.8.0)
org.eclipse.emf.cdo.protocol (0.8.0)
org.eclipse.emf.cdo.ui (0.8.0)
org.eclipse.emf.net4j (0.8.0)
org.eclipse.emf.net4j.db (0.8.0)
org.eclipse.emf.net4j.db.derby (0.8.0)
org.eclipse.emf.net4j.tcp (0.8.0)
org.eclipse.emf.net4j.util (0.8.0)
org.eclipse.emf.net4j.util.ui (0.8.0)
(and other emf 2.4 plugins)
- In the CDO sessions view, I try to open a session using the dialog.
(Server - tcp://localhost:2036, Repository Name - repo, Legacy Support
checkbox is disabled and not checked)
- After a wait a dialog box comes up with "Unable to open a session on the
specified repository tcp://localhost:2036/repo?disableLegacyObjects=true"
- A registration error is occuring in the client
(org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel):
[ERROR] Registration timeout after 10000 milliseconds
org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Registration
timeout after 10000 milliseconds
- I've extended (and also disabled) the CDO timeout values but this hasn't
resulted in a registration.
- The client and server traces and cdo-server.xml are included below. If
needed I can access the ClientTCPConnector using the Introspector view to
retrieve any required information.
Any help would be appreciated.
=========================== cdo-server.xml ====================
<?xml version="1.0" encoding="UTF-8"?>
<cdoServer>
<acceptor type="tcp" listenAddr="0.0.0.0" port="2036">
<!--
<negotiator type="challenge" description="/temp/users.db"/>
-->
</acceptor>
<repository name="repo">
<property name="overrideUUID"
value="1ff5d226-b1f0-40fb-aba2-0c31b38c764f"/>
<property name="supportingAudits" value="true"/>
<property name="verifyingRevisions" value="false"/>
<property name="rememberingKnownTypes" value="false"/>
<property name="currentLRUCapacity" value="10000"/>
<property name="revisedLRUCapacity" value="100"/>
<store type="db">
<!-- type: horizontal | vertical | <any user-contributed type>-->
<mappingStrategy type="horizontal">
<!-- ONE_TABLE_PER_REFERENCE | ONE_TABLE_PER_CLASS |
ONE_TABLE_PER_PACKAGE | ONE_TABLE_PER_REPOSITORY | LIKE_ATTRIBUTES -->
<property name="toManyReferences"
value="ONE_TABLE_PER_REFERENCE"/>
<!-- LIKE_ATTRIBUTES | LIKE_TO_MANY_REFERENCES-->
<property name="toOneReferences" value="LIKE_ATTRIBUTES"/>
<!-- MODEL | STRATEGY-->
<property name="mappingPrecedence" value="MODEL"/>
</mappingStrategy>
<dbAdapter name="derby"/>
<dataSource class="org.apache.derby.jdbc.EmbeddedDataSource"
databaseName="/cdodb"
createDatabase="create"/>
<!-- <dbAdapter name="derby"/>
<dataSource class="org.apache.derby.jdbc.ClientDataSource"
databaseName="cdodb"
createDatabase="create"/>-->
<!--<dbAdapter name="hsqldb"/>
<dataSource class="org.eclipse.net4j.db.hsqldb.HSQLDBDataSource"
database="jdbc:hsqldb:mem:cdodb1"
user="sa"/>-->
<!--<dbAdapter name="mysql"/>
<dataSource class="com.mysql.jdbc.jdbc2.optional.MysqlDataSource"
url="jdbc:mysql://localhost/cdodb1"
user="sa"/>-->
</store>
</repository>
</cdoServer>
=========================== Server Trace ========================
Configuration location:
file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
Reduced/
Configuration file:
file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
Reduced/config.ini loaded
Install location:
file:/Applications/eclipse 3.4/eclipse/
Framework located:
file:/Applications/eclipse
3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
Framework classpath:
file:/Applications/eclipse
3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
Splash location:
null
Debug options:
file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
Reduced/.options loaded
osgi> Time to load bundles: 483
Starting application: 3526
Thread-0 [debug.om] Starting bundle org.eclipse.net4j.util
Thread-0 [debug.lifecycle] Activating ManagedContainer
Thread-0 [debug.lifecycle] Activating {}
Thread-0 [debug.lifecycle.dump] DUMP PluginFactoryRegistry@1
Registry.autoCommit = true
Registry.transaction = null
HashMapRegistry.map =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
file]
org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
challenge]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
cdo]
extensionRegistryListener =
org.eclipse.net4j.internal.util.factory.PluginFactoryRegistr y$1@12ce69
Thread-0 [debug.lifecycle] Activating []
Thread-0 [debug.om] Starting bundle org.eclipse.net4j
Thread-0 [debug.om] Starting bundle org.eclipse.net4j.tcp
Thread-0 [debug.lifecycle.dump] DUMP PluginElementProcessorList@2
processors =
org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
extensionRegistryListener =
org.eclipse.net4j.internal.util.container.PluginElementProce ssorList$1@594680
Thread-0 [debug.lifecycle.dump] DUMP PluginContainer@3
ManagedContainer.factoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
file]
org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
challenge]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
cdo]
ManagedContainer.postProcessors =
org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
ManagedContainer.elementRegistry =
ManagedContainer.maxElementID = 0
ManagedContainer.elementListener =
org.eclipse.net4j.internal.util.container.ManagedContainer$1@d6c8b9
Thread-0 [debug.om] Plugin container created: ManagedContainer
Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.server
Thread-0 [debug.om] Starting application org.eclipse.emf.cdo.server.app
[INFO] CDO Server starting
Thread-0 [debug.repository] Configuring CDO server from workspace/CDO
Server/server/config/cdo-server.xml
Thread-0 [debug.repository] Configuring repository repo (type=default)
Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.protocol
Thread-0 [debug.model] Created
CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0, name=cdocore,
dynamic=false, metaIDRange=null)
Thread-0 [debug.model] Created CDOClass(ID=0, name=CDOObject)
Thread-0 [debug.model] Adding class: CDOClass(ID=0, name=CDOObject)
Thread-0 [debug.model] Added package:
CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0, name=cdocore,
dynamic=false, metaIDRange=null)
Thread-0 [debug.model] Created
CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null)
Thread-0 [debug.model] Created CDOClass(ID=0, name=CDOResource)
Thread-0 [debug.model] Created CDOFeature(ID=9, name=path, type=STRING,
referenceType=null)
Thread-0 [debug.model] Adding feature: CDOFeature(ID=9, name=path,
type=STRING, referenceType=null)
Thread-0 [debug.model] Created CDOFeature(ID=2, name=contents,
type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
Thread-0 [debug.model] Adding feature: CDOFeature(ID=2, name=contents,
type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
Thread-0 [debug.model] Adding class: CDOClass(ID=0, name=CDOResource)
Thread-0 [debug.model] Added package:
CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null)
Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.server.db
Thread-0 [debug.om] Starting bundle org.eclipse.net4j.db
Thread-0 [debug.lifecycle] Activating Repository[repo, null]
Thread-0 [debug.lifecycle] Activating DBStore@4
Thread-0 [debug.sql] CREATE TABLE cdo_classes (id INTEGER, package
INTEGER, classifier INTEGER, name VARCHAR(255), abstract SMALLINT)
Thread-0 [debug.sql] -- Table/View 'CDO_CLASSES' already exists in Schema
'APP'.
Thread-0 [debug.sql] CREATE TABLE cdo_supertypes (type_id INTEGER,
supertype_package VARCHAR(255), supertype_classifier INTEGER)
Thread-0 [debug.sql] -- Table/View 'CDO_SUPERTYPES' already exists in
Schema 'APP'.
Thread-0 [debug.sql] CREATE TABLE cdo_features (id INTEGER, class INTEGER,
feature INTEGER, name VARCHAR(255), type INTEGER, reference_package
VARCHAR(255), reference_classifier INTEGER, many SMALLINT, containment
SMALLINT, idx INTEGER)
Thread-0 [debug.sql] -- Table/View 'CDO_FEATURES' already exists in Schema
'APP'.
Thread-0 [debug.sql] CREATE TABLE cdo_repository (name VARCHAR(255), uuid
VARCHAR(64), starts BIGINT, started BIGINT, stopped BIGINT, next_cdoid
BIGINT, next_metaid BIGINT)
Thread-0 [debug.sql] -- Table/View 'CDO_REPOSITORY' already exists in
Schema 'APP'.
Thread-0 [debug.sql] CREATE TABLE cdo_packages (id INTEGER, uri
VARCHAR(255), name VARCHAR(255), ecore CLOB, dynamic SMALLINT, range_lb
BIGINT, range_ub BIGINT)
Thread-0 [debug.sql] -- Table/View 'CDO_PACKAGES' already exists in Schema
'APP'.
Thread-0 [debug.sql] SELECT MAX(next_cdoid) FROM cdo_repository
Thread-0 [debug.sql] SELECT MAX(next_metaid) FROM cdo_repository
Thread-0 [debug.sql] UPDATE cdo_repository SET starts=starts+1,
started=1208142625647, stopped=0, next_cdoid=-1, next_metaid=-1
Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_packages
Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_classes
Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_features
Thread-0 [debug.lifecycle] Activating horizontal
Thread-0 [debug.lifecycle] Activating ObjectTypeCache@5
Thread-0 [debug.lifecycle.dump] DUMP ObjectTypeCache@5
mappingStrategy = horizontal
table = null
idField = null
typeField = null
initializeLock = java.lang.Object@70f15e
Thread-0 [debug.lifecycle.dump] DUMP HorizontalMappingStrategy@6
MappingStrategy.store = DBStore@4
MappingStrategy.properties =
toOneReferences=LIKE_ATTRIBUTES
toManyReferences=ONE_TABLE_PER_REFERENCE
mappingPrecedence=MODEL
MappingStrategy.referenceTables =
MappingStrategy.classRefs =
MappingStrategy.resourceClassMapping = null
MappingStrategy.resourcePathMapping = null
MappingStrategy.resourceTable = null
MappingStrategy.resourceIDField = null
MappingStrategy.resourcePathField = null
objectTypeCache = ObjectTypeCache@5
Thread-0 [debug.lifecycle.dump] DUMP DBStore@4
Store.type = db
Store.properties = null
Store.repository = Repository[repo, null]
LongIDStore.lastObjectID = 2
mappingStrategy = horizontal
dbSchema = null
dbAdapter = derby-10.2.2.0
dbConnectionProvider = org.apache.derby.jdbc.EmbeddedDataSource@a91761
nextPackageID = 1
nextClassID = 1
nextFeatureID = 1
Thread-0 [debug.lifecycle] Activating PackageManager@7
Thread-0 [debug.sql] SELECT uri, dynamic, range_lb, range_ub FROM
cdo_packages
Thread-0 [debug.lifecycle.dump] DUMP PackageManager@7
CDOPackageManagerImpl.packages =
http://www.eclipse.org/emf/CDO/core/1.0.0=CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
name=cdocore, dynamic=false, metaIDRange=null)
http://www.eclipse.org/emf/CDO/resource/1.0.0=CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null)
CDOPackageManagerImpl.cdoCorePackage =
CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0, name=cdocore,
dynamic=false, metaIDRange=null)
CDOPackageManagerImpl.cdoResourcePackage =
CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null)
repository = Repository[repo, null]
Thread-0 [debug.lifecycle] Activating SessionManager@8
Thread-0 [debug.lifecycle.dump] DUMP SessionManager@8
repository = Repository[repo, null]
sessions =
lastSessionID = 0
Thread-0 [debug.lifecycle] Activating ResourceManager@9
Thread-0 [debug.lifecycle.dump] DUMP ResourceManager@9
repository = Repository[repo, null]
idToPathMap =
pathToIDMap =
Thread-0 [debug.lifecycle] Activating RevisionManager@10
Thread-0 [debug.lifecycle.dump] DUMP RevisionManager@10
CDORevisionResolverImpl.revisions =
CDORevisionResolverImpl.currentLRUCapacity = 10000
CDORevisionResolverImpl.revisedLRUCapacity = 100
CDORevisionResolverImpl.currentLRU = LRU[size=0, capacity=10,000]
CDORevisionResolverImpl.revisedLRU = LRU[size=0, capacity=100]
repository = Repository[repo, null]
cdoPathFeature = CDOFeature(ID=9, name=path, type=STRING,
referenceType=null)
Thread-0 [debug.lifecycle.dump] DUMP Repository@11
name = repo
store = DBStore@4
uuid = null
properties =
revisedLRUCapacity=100
rememberingKnownTypes=false
supportingAudits=true
verifyingRevisions=false
overrideUUID=1ff5d226-b1f0-40fb-aba2-0c31b38c764f
currentLRUCapacity=10000
supportingRevisionDeltas = null
supportingAudits = true
verifyingRevisions = null
packageManager = PackageManager@7
sessionManager = SessionManager@8
resourceManager = ResourceManager@9
revisionManager = RevisionManager@10
elements = [Lorg.eclipse.emf.cdo.server.IRepositoryElement;@10609a
lastMetaID = 0
Thread-0 [debug] Configuring Net4j server from workspace/CDO
Server/server/config/cdo-server.xml
Thread-0 [debug.lifecycle] Activating BufferPool[4,096]
BufferPoolMonitor [debug.buffer] Start monitoring
Thread-0 [debug.lifecycle.dump] DUMP BufferPool@12
BufferProvider.bufferCapacity = 4096
BufferProvider.providedBuffers = 0
BufferProvider.retainedBuffers = 0
provider = BufferFactory[4,096]
pooledBuffers = 0
Thread-0 [debug.lifecycle] Activating TCPSelector
Thread-0 [debug.lifecycle.dump] DUMP TCPSelector@13
selector = sun.nio.ch.KQueueSelectorImpl@c20307
clientOperations =
serverOperations =
thread = Thread[TCPSelector,5,main]
running = true
Thread-0 [debug.lifecycle] Activating TCPAcceptor[0.0.0.0:2,036]
Thread-0 [debug] Ordering server operation REGISTER
sun.nio.ch.ServerSocketChannelImpl[unbound]
TCPSelector [debug] Executing server operation REGISTER
sun.nio.ch.ServerSocketChannelImpl[unbound]
TCPSelector [debug] Registering sun.nio.ch.ServerSocketChannelImpl[unbound]
Thread-0 [debug.lifecycle.dump] DUMP TCPAcceptor@14
Acceptor.negotiator = null
Acceptor.bufferProvider = BufferPool[4,096]
Acceptor.protocolFactoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
file]
org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
challenge]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
cdo]
Acceptor.protocolPostProcessors =
org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@c6482
Acceptor.lifecycleEventConverter =
org.eclipse.internal.net4j.acceptor.Acceptor$1@9ab21d
Acceptor.acceptedConnectors =
selector = TCPSelector
selectionKey = sun.nio.ch.SelectionKeyImpl@85a317
startSynchronously = true
synchronousStartTimeout = 4000
startLatch = java.util.concurrent.CountDownLatch@af3479[Count = 0]
serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
address = 0.0.0.0
port = 2036
[INFO] CDO Server started
Application Started: 14098
=========================== Client Trace ========================
Configuration location:
file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
Workspace/
Configuration file:
file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
Workspace/config.ini loaded
Install location:
file:/Applications/eclipse 3.4/eclipse/
Framework located:
file:/Applications/eclipse
3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
Framework classpath:
file:/Applications/eclipse
3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
Debug options:
file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
Workspace/.options loaded
osgi> Time to load bundles: 25
Starting application: 2843
Application Started: 13665
[INFO] Legacy system not available
Worker-4 [debug.model] Created
CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0, name=cdocore,
dynamic=false, metaIDRange=null)
Worker-4 [debug.model] Created CDOClass(ID=0, name=CDOObject)
Worker-4 [debug.model] Adding class: CDOClass(ID=0, name=CDOObject)
Worker-4 [debug.model] Added package:
CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0, name=cdocore,
dynamic=false, metaIDRange=null)
Worker-4 [debug.model] Created
CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null)
Worker-4 [debug.model] Created CDOClass(ID=0, name=CDOResource)
Worker-4 [debug.model] Created CDOFeature(ID=9, name=path, type=STRING,
referenceType=null)
Worker-4 [debug.model] Adding feature: CDOFeature(ID=9, name=path,
type=STRING, referenceType=null)
Worker-4 [debug.model] Created CDOFeature(ID=2, name=contents,
type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
Worker-4 [debug.model] Adding feature: CDOFeature(ID=2, name=contents,
type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
Worker-4 [debug.model] Adding class: CDOClass(ID=0, name=CDOResource)
Worker-4 [debug.model] Added package:
CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null)
Worker-4 [debug.model] Setting client info:
CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0, name=cdocore,
dynamic=false, metaIDRange=null) -->
org.eclipse.emf.ecore.impl.EcorePackageImpl@c76d78 (name: ecore) (nsURI:
http://www.eclipse.org/emf/2002/Ecore, nsPrefix: ecore)
Worker-4 [debug.model] Setting client info: CDOClass(ID=0, name=CDOObject)
--> org.eclipse.emf.ecore.impl.EClassImpl@e3afa9 (name: EObject)
(instanceClassName: null) (abstract: false, interface: false)
Worker-4 [debug.model] Setting client info:
CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
name=cdoresource, dynamic=false, metaIDRange=null) -->
org.eclipse.emf.cdo.eresource.impl.EresourcePackageImpl@bc80d8 (name:
eresource) (nsURI: http://www.eclipse.org/emf/CDO/resource/1.0.0,
nsPrefix: eresource)
Worker-4 [debug.model] Setting client info: CDOClass(ID=0,
name=CDOResource) --> org.eclipse.emf.ecore.impl.EClassImpl@1033db (name:
CDOResource) (instanceClassName: null) (abstract: false, interface: false)
Worker-4 [debug.model] Setting client info: CDOFeature(ID=2,
name=contents, type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
--> org.eclipse.emf.ecore.impl.EReferenceImpl@ad3677 (name: contents)
(ordered: true, unique: true, lowerBound: 0, upperBound: -1) (changeable:
true, volatile: false, transient: false, defaultValueLiteral: null,
unsettable: false, derived: false) (containment: true, resolveProxies:
false)
Worker-4 [debug.model] Setting client info: CDOFeature(ID=9, name=path,
type=STRING, referenceType=null) -->
org.eclipse.emf.ecore.impl.EAttributeImpl@d2eead (name: path) (ordered:
true, unique: true, lowerBound: 0, upperBound: 1) (changeable: true,
volatile: false, transient: false, defaultValueLiteral: null, unsettable:
false, derived: false) (iD: false)
Worker-4 [debug.connector] Setting userID null for
ClientTCPConnector[null:0]
BufferPoolMonitor [debug.buffer] Start monitoring
BufferPoolMonitor [debug.buffer] Stop monitoring
Worker-4 [debug.connector] Setting state CONNECTING (was disconnected) for
ClientTCPConnector[localhost:2,036]
Worker-4 [debug] Ordering client operation REGISTER
java.nio.channels.SocketChannel[unconnected]
TCPSelector [debug] Executing client operation REGISTER
java.nio.channels.SocketChannel[unconnected]
TCPSelector [debug] Registering
java.nio.channels.SocketChannel[unconnected]
TCPSelector [debug] Connecting
java.nio.channels.SocketChannel[connection-pending
remote=localhost/127.0.0.1:2036]
TCPSelector [debug] Ordering client operation INTEREST CONNECT
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = false
TCPSelector [debug] Ordering client operation INTEREST READ
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = true
TCPSelector [debug.connector] Setting state CONNECTED (was connecting) for
ClientTCPConnector[localhost:2,036]
TCPSelector [debug] Executing client operation INTEREST CONNECT
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = false
TCPSelector [debug] Setting interest (was connect)
TCPSelector [debug] Executing client operation INTEREST READ
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = true
TCPSelector [debug] Setting interest READ
Worker-4 [debug.connector] Waiting for connection...
Worker-4 [debug.connector] Opening channel 0 with protocol cdo
Worker-4 [debug] Registering channel 0 with protocol SignalProtocol[cdo]
Worker-4 [debug.buffer] Created Buffer@1
Worker-4 [debug.buffer] Obtained Buffer@1
Worker-4 [debug.channel] Handling buffer from client: Buffer@1 -->
Channel[Control]
Worker-4 [debug] Ordering client operation INTEREST WRITE
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = true
TCPSelector [debug] Executing client operation INTEREST WRITE
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = true
TCPSelector [debug] Setting interest READ|WRITE (was read)
TCPSelector [debug] Writing java.nio.channels.SocketChannel[connected
local=/127.0.0.1:51054 remote=localhost/127.0.0.1:2036]
TCPSelector [debug.buffer] Writing 12 bytes
02 00 00 00 01 00 00 00 03 63 64 6f
TCPSelector [debug.buffer] Retaining Buffer@1
TCPSelector [debug] Ordering client operation INTEREST WRITE
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = false
TCPSelector [debug] Executing client operation INTEREST WRITE
java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
remote=localhost/127.0.0.1:2036] = false
TCPSelector [debug] Setting interest READ (was read|write)
[ERROR] Registration timeout after 10000 milliseconds
org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Registration
timeout after 10000 milliseconds
at
org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
at
org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
at
org.eclipse.emf.internal.cdo.CDOSessionImpl.doActivate(CDOSe ssionImpl.java:623)
at
org.eclipse.net4j.internal.util.lifecycle.Lifecycle.activate (Lifecycle.java:57)
at
org.eclipse.net4j.util.lifecycle.LifecycleUtil.activate(Life cycleUtil.java:71)
at
org.eclipse.net4j.util.lifecycle.LifecycleUtil.activate(Life cycleUtil.java:61)
at
org.eclipse.net4j.internal.util.container.ManagedContainer.g etElement(ManagedContainer.java:260)
at
org.eclipse.emf.cdo.internal.ui.actions.OpenSessionAction.do Run(OpenSessionAction.java:70)
at
org.eclipse.net4j.util.ui.actions.LongRunningAction$1.run(Lo ngRunningAction.java:164)
at
org.eclipse.net4j.util.om.monitor.MonitoredJob.run(Monitored Job.java:48)
at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
|
|
|
| Re: [CDO] Client registration timeout exception [message #118223 is a reply to message #118189] |
Mon, 14 April 2008 07:57  |
| Eclipse User |
|
|
|
Originally posted by: stepper.sympedia.de
Hi Ben,
Comments inline...
Ben schrieb:
> I'm new to CDO and I'm trying to connect to a CDO server using the
> "CDO Sessions View"
> (org.eclipse.emf.cdo.CDOSession.CDOSessionsView). Here is rundown of
> what I'm doing:
>
> - JVM 1.5.0 (using OS X) , Eclipse 3.4m5,
> - I run a CDO server using the product configuration
> org.eclipse.emf.cdo.server.product.
> - I run an eclipse workbench configuration with the following
> additional plugins:
> org.eclipse.emf.cdo (0.8.0)
> org.eclipse.emf.cdo.edit (0.8.0)
> org.eclipse.emf.cdo.protocol (0.8.0)
> org.eclipse.emf.cdo.ui (0.8.0)
> org.eclipse.emf.net4j (0.8.0)
> org.eclipse.emf.net4j.db (0.8.0)
> org.eclipse.emf.net4j.db.derby (0.8.0)
> org.eclipse.emf.net4j.tcp (0.8.0) org.eclipse.emf.net4j.util
> (0.8.0)
> org.eclipse.emf.net4j.util.ui (0.8.0)
> (and other emf 2.4 plugins)
All of the 0.8.0 builds are integration builds and breaking changes can
occur at any time. Thus you must ensure that server and client plugins
come from the same build!
> - In the CDO sessions view, I try to open a session using the dialog.
> (Server - tcp://localhost:2036, Repository Name - repo, Legacy Support
> checkbox is disabled and not checked)
>
> - After a wait a dialog box comes up with "Unable to open a session on
> the specified repository
> tcp://localhost:2036/repo?disableLegacyObjects=true"
>
> - A registration error is occuring in the client
> (org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel):
>
> [ERROR] Registration timeout after 10000 milliseconds
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
>
>
> - I've extended (and also disabled) the CDO timeout values but this
> hasn't resulted in a registration.
> - The client and server traces and cdo-server.xml are included below.
> If needed I can access the ClientTCPConnector using the Introspector
> view to retrieve any required information.
> Any help would be appreciated.
Your configurations seem to be ok.
Here on my Windows box everything works as expected.
Maybe it's a Mac OS related issue which I fear I can't debug here ;-(
Is your problem reproducible?
The logs that you pasted look ok up to the point with the client exception.
Maybe you can start debugging at a lower and simpler level.
I just committed a pure Net4j example. Can you please verify that the
ECHOProtocol is able to run on Mac OS?
- org.eclipse.net4j.examples.echo.server.EchoServer
- org.eclipse.net4j.examples.echo.client.EchoClient
When you want to debug your setup I suggest that you start somewhere in
- org.eclipse.net4j.internal.tcp.TCPAcceptor.handleAccept(ITCP Selector,
ServerSocketChannel)
- org.eclipse.internal.net4j.connector.Connector.createChannel (int,
short, String)
Sorry, as long as there is no exception in the trace (of the server
side) or I can reproduce the problem here it's hard to find the cause ;-(
Cheers
/Eike
>
> =========================== cdo-server.xml ====================
>
> <?xml version="1.0" encoding="UTF-8"?>
> <cdoServer>
>
>
> <acceptor type="tcp" listenAddr="0.0.0.0" port="2036">
> <!--
> <negotiator type="challenge" description="/temp/users.db"/> -->
> </acceptor>
>
> <repository name="repo">
> <property name="overrideUUID"
> value="1ff5d226-b1f0-40fb-aba2-0c31b38c764f"/>
> <property name="supportingAudits" value="true"/>
> <property name="verifyingRevisions" value="false"/>
> <property name="rememberingKnownTypes" value="false"/>
The above property is not supported anymore. You can remove it (although
this doesn't cause your problem)
> <property name="currentLRUCapacity" value="10000"/>
> <property name="revisedLRUCapacity" value="100"/>
> <store type="db">
> <!-- type: horizontal | vertical | <any user-contributed type>-->
> <mappingStrategy type="horizontal">
> <!-- ONE_TABLE_PER_REFERENCE | ONE_TABLE_PER_CLASS |
> ONE_TABLE_PER_PACKAGE | ONE_TABLE_PER_REPOSITORY | LIKE_ATTRIBUTES -->
> <property name="toManyReferences"
> value="ONE_TABLE_PER_REFERENCE"/>
>
> <!-- LIKE_ATTRIBUTES | LIKE_TO_MANY_REFERENCES-->
> <property name="toOneReferences" value="LIKE_ATTRIBUTES"/>
> <!-- MODEL | STRATEGY-->
> <property name="mappingPrecedence" value="MODEL"/>
> </mappingStrategy>
> <dbAdapter name="derby"/>
> <dataSource class="org.apache.derby.jdbc.EmbeddedDataSource"
> databaseName="/cdodb"
> createDatabase="create"/>
>
> <!-- <dbAdapter name="derby"/>
> <dataSource class="org.apache.derby.jdbc.ClientDataSource"
> databaseName="cdodb"
> createDatabase="create"/>-->
>
> <!--<dbAdapter name="hsqldb"/>
> <dataSource class="org.eclipse.net4j.db.hsqldb.HSQLDBDataSource"
> database="jdbc:hsqldb:mem:cdodb1"
> user="sa"/>-->
>
> <!--<dbAdapter name="mysql"/>
> <dataSource class="com.mysql.jdbc.jdbc2.optional.MysqlDataSource"
> url="jdbc:mysql://localhost/cdodb1"
> user="sa"/>-->
> </store>
> </repository>
>
> </cdoServer>
>
> =========================== Server Trace
> ========================
>
>
>
> Configuration location:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
> Reduced/
> Configuration file:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
> Reduced/config.ini loaded
> Install location:
> file:/Applications/eclipse 3.4/eclipse/
> Framework located:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Framework classpath:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Splash location:
> null
> Debug options:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
> Reduced/.options loaded
>
> osgi> Time to load bundles: 483
> Starting application: 3526
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j.util
> Thread-0 [debug.lifecycle] Activating ManagedContainer
> Thread-0 [debug.lifecycle] Activating {}
> Thread-0 [debug.lifecycle.dump] DUMP PluginFactoryRegistry@1
> Registry.autoCommit = true
> Registry.transaction = null
> HashMapRegistry.map =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
> file]
>
> org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
> challenge]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
> cdo]
> extensionRegistryListener =
> org.eclipse.net4j.internal.util.factory.PluginFactoryRegistr y$1@12ce69
>
> Thread-0 [debug.lifecycle] Activating []
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j.tcp
> Thread-0 [debug.lifecycle.dump] DUMP PluginElementProcessorList@2
> processors =
> org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
>
> org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
> extensionRegistryListener =
> org.eclipse.net4j.internal.util.container.PluginElementProce ssorList$1@594680
>
>
> Thread-0 [debug.lifecycle.dump] DUMP PluginContainer@3
> ManagedContainer.factoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
> file]
>
> org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
> challenge]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
> cdo]
> ManagedContainer.postProcessors =
> org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
>
> org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
> ManagedContainer.elementRegistry = ManagedContainer.maxElementID = 0
> ManagedContainer.elementListener =
> org.eclipse.net4j.internal.util.container.ManagedContainer$1@d6c8b9
>
> Thread-0 [debug.om] Plugin container created: ManagedContainer
> Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.server
> Thread-0 [debug.om] Starting application org.eclipse.emf.cdo.server.app
> [INFO] CDO Server starting
> Thread-0 [debug.repository] Configuring CDO server from workspace/CDO
> Server/server/config/cdo-server.xml
> Thread-0 [debug.repository] Configuring repository repo (type=default)
> Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.protocol
> Thread-0 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Thread-0 [debug.model] Created CDOClass(ID=0, name=CDOObject)
> Thread-0 [debug.model] Adding class: CDOClass(ID=0, name=CDOObject)
> Thread-0 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Thread-0 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Thread-0 [debug.model] Created CDOClass(ID=0, name=CDOResource)
> Thread-0 [debug.model] Created CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Thread-0 [debug.model] Adding feature: CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Thread-0 [debug.model] Created CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Thread-0 [debug.model] Adding feature: CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Thread-0 [debug.model] Adding class: CDOClass(ID=0, name=CDOResource)
> Thread-0 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.server.db
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j.db
> Thread-0 [debug.lifecycle] Activating Repository[repo, null]
> Thread-0 [debug.lifecycle] Activating DBStore@4
> Thread-0 [debug.sql] CREATE TABLE cdo_classes (id INTEGER, package
> INTEGER, classifier INTEGER, name VARCHAR(255), abstract SMALLINT)
> Thread-0 [debug.sql] -- Table/View 'CDO_CLASSES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_supertypes (type_id INTEGER,
> supertype_package VARCHAR(255), supertype_classifier INTEGER)
> Thread-0 [debug.sql] -- Table/View 'CDO_SUPERTYPES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_features (id INTEGER, class
> INTEGER, feature INTEGER, name VARCHAR(255), type INTEGER,
> reference_package VARCHAR(255), reference_classifier INTEGER, many
> SMALLINT, containment SMALLINT, idx INTEGER)
> Thread-0 [debug.sql] -- Table/View 'CDO_FEATURES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_repository (name VARCHAR(255),
> uuid VARCHAR(64), starts BIGINT, started BIGINT, stopped BIGINT,
> next_cdoid BIGINT, next_metaid BIGINT)
> Thread-0 [debug.sql] -- Table/View 'CDO_REPOSITORY' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_packages (id INTEGER, uri
> VARCHAR(255), name VARCHAR(255), ecore CLOB, dynamic SMALLINT,
> range_lb BIGINT, range_ub BIGINT)
> Thread-0 [debug.sql] -- Table/View 'CDO_PACKAGES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] SELECT MAX(next_cdoid) FROM cdo_repository
> Thread-0 [debug.sql] SELECT MAX(next_metaid) FROM cdo_repository
> Thread-0 [debug.sql] UPDATE cdo_repository SET starts=starts+1,
> started=1208142625647, stopped=0, next_cdoid=-1, next_metaid=-1
> Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_packages
> Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_classes
> Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_features
> Thread-0 [debug.lifecycle] Activating horizontal
> Thread-0 [debug.lifecycle] Activating ObjectTypeCache@5
> Thread-0 [debug.lifecycle.dump] DUMP ObjectTypeCache@5
> mappingStrategy = horizontal
> table = null
> idField = null
> typeField = null
> initializeLock = java.lang.Object@70f15e
>
> Thread-0 [debug.lifecycle.dump] DUMP HorizontalMappingStrategy@6
> MappingStrategy.store = DBStore@4
> MappingStrategy.properties = toOneReferences=LIKE_ATTRIBUTES
> toManyReferences=ONE_TABLE_PER_REFERENCE
> mappingPrecedence=MODEL
> MappingStrategy.referenceTables = MappingStrategy.classRefs =
> MappingStrategy.resourceClassMapping = null
> MappingStrategy.resourcePathMapping = null
> MappingStrategy.resourceTable = null
> MappingStrategy.resourceIDField = null
> MappingStrategy.resourcePathField = null
> objectTypeCache = ObjectTypeCache@5
>
> Thread-0 [debug.lifecycle.dump] DUMP DBStore@4
> Store.type = db
> Store.properties = null
> Store.repository = Repository[repo, null]
> LongIDStore.lastObjectID = 2
> mappingStrategy = horizontal
> dbSchema = null
> dbAdapter = derby-10.2.2.0
> dbConnectionProvider = org.apache.derby.jdbc.EmbeddedDataSource@a91761
> nextPackageID = 1
> nextClassID = 1
> nextFeatureID = 1
>
> Thread-0 [debug.lifecycle] Activating PackageManager@7
> Thread-0 [debug.sql] SELECT uri, dynamic, range_lb, range_ub FROM
> cdo_packages
> Thread-0 [debug.lifecycle.dump] DUMP PackageManager@7
> CDOPackageManagerImpl.packages =
> http://www.eclipse.org/emf/CDO/core/1.0.0=CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
>
> http://www.eclipse.org/emf/CDO/resource/1.0.0=CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> CDOPackageManagerImpl.cdoCorePackage =
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> CDOPackageManagerImpl.cdoResourcePackage =
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> repository = Repository[repo, null]
>
> Thread-0 [debug.lifecycle] Activating SessionManager@8
> Thread-0 [debug.lifecycle.dump] DUMP SessionManager@8
> repository = Repository[repo, null]
> sessions = lastSessionID = 0
>
> Thread-0 [debug.lifecycle] Activating ResourceManager@9
> Thread-0 [debug.lifecycle.dump] DUMP ResourceManager@9
> repository = Repository[repo, null]
> idToPathMap = pathToIDMap =
> Thread-0 [debug.lifecycle] Activating RevisionManager@10
> Thread-0 [debug.lifecycle.dump] DUMP RevisionManager@10
> CDORevisionResolverImpl.revisions =
> CDORevisionResolverImpl.currentLRUCapacity = 10000
> CDORevisionResolverImpl.revisedLRUCapacity = 100
> CDORevisionResolverImpl.currentLRU = LRU[size=0, capacity=10,000]
> CDORevisionResolverImpl.revisedLRU = LRU[size=0, capacity=100]
> repository = Repository[repo, null]
> cdoPathFeature = CDOFeature(ID=9, name=path, type=STRING,
> referenceType=null)
>
> Thread-0 [debug.lifecycle.dump] DUMP Repository@11
> name = repo
> store = DBStore@4
> uuid = null
> properties = revisedLRUCapacity=100
> rememberingKnownTypes=false
> supportingAudits=true
> verifyingRevisions=false
> overrideUUID=1ff5d226-b1f0-40fb-aba2-0c31b38c764f
> currentLRUCapacity=10000
> supportingRevisionDeltas = null
> supportingAudits = true
> verifyingRevisions = null
> packageManager = PackageManager@7
> sessionManager = SessionManager@8
> resourceManager = ResourceManager@9
> revisionManager = RevisionManager@10
> elements = [Lorg.eclipse.emf.cdo.server.IRepositoryElement;@10609a
> lastMetaID = 0
>
> Thread-0 [debug] Configuring Net4j server from workspace/CDO
> Server/server/config/cdo-server.xml
> Thread-0 [debug.lifecycle] Activating BufferPool[4,096]
> BufferPoolMonitor [debug.buffer] Start monitoring
> Thread-0 [debug.lifecycle.dump] DUMP BufferPool@12
> BufferProvider.bufferCapacity = 4096
> BufferProvider.providedBuffers = 0
> BufferProvider.retainedBuffers = 0
> provider = BufferFactory[4,096]
> pooledBuffers = 0
>
> Thread-0 [debug.lifecycle] Activating TCPSelector
> Thread-0 [debug.lifecycle.dump] DUMP TCPSelector@13
> selector = sun.nio.ch.KQueueSelectorImpl@c20307
> clientOperations = serverOperations = thread = Thread[TCPSelector,5,main]
> running = true
>
> Thread-0 [debug.lifecycle] Activating TCPAcceptor[0.0.0.0:2,036]
> Thread-0 [debug] Ordering server operation REGISTER
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [debug] Executing server operation REGISTER
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [debug] Registering
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> Thread-0 [debug.lifecycle.dump] DUMP TCPAcceptor@14
> Acceptor.negotiator = null
> Acceptor.bufferProvider = BufferPool[4,096]
> Acceptor.protocolFactoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
> file]
>
> org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
> challenge]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
> cdo]
> Acceptor.protocolPostProcessors =
> org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
>
> org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
> Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@c6482
> Acceptor.lifecycleEventConverter =
> org.eclipse.internal.net4j.acceptor.Acceptor$1@9ab21d
> Acceptor.acceptedConnectors = selector = TCPSelector
> selectionKey = sun.nio.ch.SelectionKeyImpl@85a317
> startSynchronously = true
> synchronousStartTimeout = 4000
> startLatch = java.util.concurrent.CountDownLatch@af3479[Count = 0]
> serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
> address = 0.0.0.0
> port = 2036
>
> [INFO] CDO Server started
> Application Started: 14098
>
>
>
> =========================== Client Trace
> ========================
>
>
> Configuration location:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
> Workspace/
> Configuration file:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
> Workspace/config.ini loaded
> Install location:
> file:/Applications/eclipse 3.4/eclipse/
> Framework located:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Framework classpath:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Debug options:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
> Workspace/.options loaded
>
> osgi> Time to load bundles: 25
> Starting application: 2843
> Application Started: 13665
> [INFO] Legacy system not available
> Worker-4 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Created CDOClass(ID=0, name=CDOObject)
> Worker-4 [debug.model] Adding class: CDOClass(ID=0, name=CDOObject)
> Worker-4 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Created CDOClass(ID=0, name=CDOResource)
> Worker-4 [debug.model] Created CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Worker-4 [debug.model] Adding feature: CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Worker-4 [debug.model] Created CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Worker-4 [debug.model] Adding feature: CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Worker-4 [debug.model] Adding class: CDOClass(ID=0, name=CDOResource)
> Worker-4 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Setting client info:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null) -->
> org.eclipse.emf.ecore.impl.EcorePackageImpl@c76d78 (name: ecore)
> (nsURI: http://www.eclipse.org/emf/2002/Ecore, nsPrefix: ecore)
> Worker-4 [debug.model] Setting client info: CDOClass(ID=0,
> name=CDOObject) --> org.eclipse.emf.ecore.impl.EClassImpl@e3afa9
> (name: EObject) (instanceClassName: null) (abstract: false, interface:
> false)
> Worker-4 [debug.model] Setting client info:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null) -->
> org.eclipse.emf.cdo.eresource.impl.EresourcePackageImpl@bc80d8 (name:
> eresource) (nsURI: http://www.eclipse.org/emf/CDO/resource/1.0.0,
> nsPrefix: eresource)
> Worker-4 [debug.model] Setting client info: CDOClass(ID=0,
> name=CDOResource) --> org.eclipse.emf.ecore.impl.EClassImpl@1033db
> (name: CDOResource) (instanceClassName: null) (abstract: false,
> interface: false)
> Worker-4 [debug.model] Setting client info: CDOFeature(ID=2,
> name=contents, type=OBJECT, referenceType=CDOClass(ID=0,
> name=CDOObject)) --> org.eclipse.emf.ecore.impl.EReferenceImpl@ad3677
> (name: contents) (ordered: true, unique: true, lowerBound: 0,
> upperBound: -1) (changeable: true, volatile: false, transient: false,
> defaultValueLiteral: null, unsettable: false, derived: false)
> (containment: true, resolveProxies: false)
> Worker-4 [debug.model] Setting client info: CDOFeature(ID=9,
> name=path, type=STRING, referenceType=null) -->
> org.eclipse.emf.ecore.impl.EAttributeImpl@d2eead (name: path)
> (ordered: true, unique: true, lowerBound: 0, upperBound: 1)
> (changeable: true, volatile: false, transient: false,
> defaultValueLiteral: null, unsettable: false, derived: false) (iD: false)
> Worker-4 [debug.connector] Setting userID null for
> ClientTCPConnector[null:0]
> BufferPoolMonitor [debug.buffer] Start monitoring
> BufferPoolMonitor [debug.buffer] Stop monitoring
> Worker-4 [debug.connector] Setting state CONNECTING (was disconnected)
> for ClientTCPConnector[localhost:2,036]
> Worker-4 [debug] Ordering client operation REGISTER
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [debug] Executing client operation REGISTER
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [debug] Registering
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [debug] Connecting
> java.nio.channels.SocketChannel[connection-pending
> remote=localhost/127.0.0.1:2036]
> TCPSelector [debug] Ordering client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Ordering client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug.connector] Setting state CONNECTED (was connecting)
> for ClientTCPConnector[localhost:2,036]
> TCPSelector [debug] Executing client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Setting interest (was connect)
> TCPSelector [debug] Executing client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug] Setting interest READ
> Worker-4 [debug.connector] Waiting for connection...
> Worker-4 [debug.connector] Opening channel 0 with protocol cdo
> Worker-4 [debug] Registering channel 0 with protocol SignalProtocol[cdo]
> Worker-4 [debug.buffer] Created Buffer@1
> Worker-4 [debug.buffer] Obtained Buffer@1
> Worker-4 [debug.channel] Handling buffer from client: Buffer@1 -->
> Channel[Control]
> Worker-4 [debug] Ordering client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug] Executing client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug] Setting interest READ|WRITE (was read)
> TCPSelector [debug] Writing java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:51054 remote=localhost/127.0.0.1:2036]
> TCPSelector [debug.buffer] Writing 12 bytes
> 02 00 00 00 01 00 00 00 03 63 64 6f TCPSelector [debug.buffer]
> Retaining Buffer@1
> TCPSelector [debug] Ordering client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Executing client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Setting interest READ (was read|write)
> [ERROR] Registration timeout after 10000 milliseconds
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
> at
> org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
>
> at
> org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
>
> at
> org.eclipse.emf.internal.cdo.CDOSessionImpl.doActivate(CDOSe ssionImpl.java:623)
>
> at
> org.eclipse.net4j.internal.util.lifecycle.Lifecycle.activate (Lifecycle.java:57)
>
> at
> org.eclipse.net4j.util.lifecycle.LifecycleUtil.activate(Life cycleUtil.java:71)
>
> at
> org.eclipse.net4j.util.lifecycle.LifecycleUtil.activate(Life cycleUtil.java:61)
>
> at
> org.eclipse.net4j.internal.util.container.ManagedContainer.g etElement(ManagedContainer.java:260)
>
> at
> org.eclipse.emf.cdo.internal.ui.actions.OpenSessionAction.do Run(OpenSessionAction.java:70)
>
> at
> org.eclipse.net4j.util.ui.actions.LongRunningAction$1.run(Lo ngRunningAction.java:164)
>
> at
> org.eclipse.net4j.util.om.monitor.MonitoredJob.run(Monitored Job.java:48)
> at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
>
>
>
>
>
>
|
|
|
| Re: [CDO] Client registration timeout exception [message #118239 is a reply to message #118223] |
Mon, 14 April 2008 09:20 |
| Eclipse User |
|
|
|
Originally posted by: ben.razzledazzle.gmail.com
Thanks for the prompt reply Eike.
- I've run the EchoClient example and I have the same error. I've
included the client and server trace below.
- For clarification, I'm running what is currently in CVS for net4j and
cdo.
- Are you using the Java SE 6? Have you tried it using Java SE 5
instead? (that is what I'm using since Java SE 6 hasn't been released on
OS X yet)
I'm debugging from the points you said but it comes back to
- org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel catching
the exception:
Exception in thread "main"
org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Registration
timeout after 10000 milliseconds
at
org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
at
org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
at
org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
- org.eclipse.net4j.internal.util.concurrent .ResultSynchronizer # public
RESULT get(long timeout) always returns a null RESULT.
- org.eclipse.net4j.internal.tcp.TCPAcceptor.handleAccept(ITCP Selector,
ServerSocketChannel) is never called.
==================== Server Trace ====================
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ManagedContainer
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
{org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
tcp],
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default],
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp],
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default],
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo],
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp],
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]}
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
HashMapRegistry@1
Registry.autoCommit = true
Registry.transaction = null
map =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ManagedContainer@2
factoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
postProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
elementRegistry =
maxElementID = 0
elementListener =
org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
BufferPool[4,096]
BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
monitoring
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
BufferPool@3
BufferProvider.bufferCapacity = 4096
BufferProvider.providedBuffers = 0
BufferProvider.retainedBuffers = 0
provider = BufferFactory[4,096]
pooledBuffers = 0
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
TCPSelector
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPSelector@4
selector = sun.nio.ch.KQueueSelectorImpl@9a029e
clientOperations =
serverOperations =
thread = Thread[TCPSelector,5,main]
running = true
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
TCPAcceptor[0.0.0.0:2,036]
main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering server
operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing server
operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
sun.nio.ch.ServerSocketChannelImpl[unbound]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPAcceptor@5
Acceptor.negotiator = null
Acceptor.bufferProvider = BufferPool[4,096]
Acceptor.protocolFactoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
Acceptor.protocolPostProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@5660d6
Acceptor.lifecycleEventConverter =
org.eclipse.internal.net4j.acceptor.Acceptor$1@ef83d3
Acceptor.acceptedConnectors =
selector = TCPSelector
selectionKey = sun.nio.ch.SelectionKeyImpl@b40ec4
startSynchronously = true
synchronousStartTimeout = 4000
startLatch = java.util.concurrent.CountDownLatch@faa550[Count = 0]
serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
address = 0.0.0.0
port = 2036
[INFO] Accepting connections: TCPAcceptor[0.0.0.0:2,036]
Press any key to shutdown
===================== Server Trace ======================
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ManagedContainer
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
{org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
tcp],
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default],
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo],
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp],
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default],
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp],
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]}
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
HashMapRegistry@1
Registry.autoCommit = true
Registry.transaction = null
map =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ManagedContainer@2
factoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
postProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
elementRegistry =
maxElementID = 0
elementListener =
org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
main [org.eclipse.internal.net4j.connector.Connector] Setting userID null
for ClientTCPConnector[null:0]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
BufferPool[4,096]
BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
monitoring
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
BufferPool@3
BufferProvider.bufferCapacity = 4096
BufferProvider.providedBuffers = 0
BufferProvider.retainedBuffers = 0
provider = BufferFactory[4,096]
pooledBuffers = 0
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
TCPSelector
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPSelector@4
selector = sun.nio.ch.KQueueSelectorImpl@722456
clientOperations =
serverOperations =
thread = Thread[TCPSelector,5,main]
running = true
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ClientTCPConnector[localhost:2,036]
main [org.eclipse.internal.net4j.connector.Connector] Setting state
CONNECTING (was disconnected) for ClientTCPConnector[localhost:2,036]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
Channel[Control]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ChannelReceiveSerializer@5
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ChannelReceiveSerializer@5
Worker.daemon = false
Worker.activationTimeout = 2000
Worker.deactivationTimeout = 2000
Worker.activationLatch = java.util.concurrent.CountDownLatch@cebc9f[Count
= 0]
Worker.workerThread = Thread[ReceiveSerializer-1,5,main]
QueueWorker.queue =
QueueWorker.pollMillis = 100
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ControlChannel@6
Channel.channelID = 0
Channel.channelMultiplexer = ClientTCPConnector[localhost:2,036]
Channel.channelIndex = -1
Channel.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@1fc1a6
Channel.receiveHandler = null
Channel.receiveSerializer = ChannelReceiveSerializer@5
Channel.sendQueue =
registrations = SynchronizingCorrelator{}
main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation REGISTER java.nio.channels.SocketChannel[unconnected]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation REGISTER java.nio.channels.SocketChannel[unconnected]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
java.nio.channels.SocketChannel[unconnected]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Connecting
java.nio.channels.SocketChannel[connection-pending
remote=localhost/127.0.0.1:2036]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST CONNECT java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST READ java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.internal.net4j.connector.Connector] Setting state
CONNECTED (was connecting) for ClientTCPConnector[localhost:2,036]
TCPSelector [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPClientConnector@7
Connector.userID = null
Connector.protocolFactoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
Connector.protocolPostProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
Connector.negotiator = null
Connector.negotiationContext = null
Connector.bufferProvider = BufferPool[4,096]
Connector.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@1fc1a6
Connector.nextChannelID = 1
Connector.channels =
Connector.channelsLock =
org.eclipse.net4j.util.concurrent.RWLock@15126e[Write locks = 0, Read
locks = 0]
Connector.connectorState = CONNECTED
Connector.channelListener =
org.eclipse.internal.net4j.connector.Connector$1@6d2380
Connector.finishedConnecting =
java.util.concurrent.CountDownLatch@35b1f3[Count = 1]
Connector.finishedNegotiating =
java.util.concurrent.CountDownLatch@35e6e3[Count = 1]
TCPConnector.socketChannel = java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036]
TCPConnector.selector = TCPSelector
TCPConnector.selectionKey = sun.nio.ch.SelectionKeyImpl@a1c42f
TCPConnector.writeQueue =
TCPConnector.inputBuffer = null
TCPConnector.controlChannel = Channel[Control]
TCPConnector.host = localhost
TCPConnector.port = 2036
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST CONNECT java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
(was connect)
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST READ java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
READ
main [org.eclipse.internal.net4j.connector.Connector] Waiting for
connection...
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
SignalProtocol[echo]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
EchoClientProtocol@8
Protocol.channel = Channel[-32,768]
Protocol.bufferProvider = BufferPool[4,096]
Protocol.executorService = java.util.concurrent.ThreadPoolExecutor@1fc1a6
Protocol.infraStructure = null
SignalProtocol.streamWrapper = null
SignalProtocol.signals =
SignalProtocol.nextCorrelationID = 1
main [org.eclipse.internal.net4j.connector.Connector] Opening channel 0
with protocol echo
main [org.eclipse.net4j.internal.tcp.ControlChannel] Registering channel 0
with protocol SignalProtocol[echo]
main [org.eclipse.internal.net4j.buffer.BufferFactory] Created Buffer@9
main [org.eclipse.internal.net4j.buffer.BufferPool] Obtained Buffer@9
main [org.eclipse.internal.net4j.channel.Channel] Handling buffer from
client: Buffer@9 --> Channel[Control]
main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
READ|WRITE (was read)
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Writing
java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
remote=localhost/127.0.0.1:2036]
TCPSelector [org.eclipse.internal.net4j.buffer.Buffer] Writing 13 bytes
02 00 00 00 01 00 00 00 04 65 63 68 6f
TCPSelector [org.eclipse.internal.net4j.buffer.BufferPool] Retaining
Buffer@9
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
READ (was read|write)
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
ManagedContainer
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
ClientTCPConnector[localhost:2,036]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
Channel[Control]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
ChannelReceiveSerializer@5
main [org.eclipse.internal.net4j.connector.Connector] Setting state
DISCONNECTED (was connected) for ClientTCPConnector[localhost:2,036]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
TCPSelector
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
BufferPool[4,096]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
{org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
tcp],
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default],
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo],
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp],
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default],
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp],
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]}
Exception in thread "main" BufferPoolMonitor
[org.eclipse.internal.net4j.buffer.BufferPool] Stop monitoring
org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Registration
timeout after 10000 milliseconds
at
org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
at
org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
at
org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
|
|
|
| Re: [CDO] Client registration timeout exception [message #118265 is a reply to message #118239] |
Mon, 14 April 2008 09:47 |
| Eclipse User |
|
|
|
Originally posted by: stepper.sympedia.de
Ben schrieb:
> Thanks for the prompt reply Eike.
>
> - I've run the EchoClient example and I have the same error. I've
> included the client and server trace below.
Ok, so we should concentrate on this simple example.
The traces don't show anything new ;-(
>
> - For clarification, I'm running what is currently in CVS for net4j
> and cdo.
That's good.
> - Are you using the Java SE 6? Have you tried it using Java SE 5
> instead? (that is what I'm using since Java SE 6 hasn't been released
> on OS X yet)
All plugins are developed against JSE-1.5 and tested on windows and linux.
More and more I tend to believe that this is related to issues with Mac
OS handling of sockets and selectors...
>
> I'm debugging from the points you said but it comes back to -
> org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel
> catching the exception:
> Exception in thread "main"
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
> at
> org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
>
> at
> org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
>
> at
> org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
>
>
>
> - org.eclipse.net4j.internal.util.concurrent .ResultSynchronizer #
> public RESULT get(long timeout) always returns a null RESULT.
> -
> org.eclipse.net4j.internal.tcp.TCPAcceptor.handleAccept(ITCP Selector,
> ServerSocketChannel) is never called.
The latter indicates that incoming connection requests are not recognized.
Again, I can't help you on Mac OS, even though I really would like to.
In TCPSelector there are a few catch blocks which don't trace
exceptions. You could add some ex.printStackTrace() there and see what
happens.
Cheers
/Eike
>
> ==================== Server Trace ====================
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ManagedContainer
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> {org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
> tcp],
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default],
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp],
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default],
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo],
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp],
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]}
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> HashMapRegistry@1
> Registry.autoCommit = true
> Registry.transaction = null
> map =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ManagedContainer@2
> factoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> postProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> elementRegistry = maxElementID = 0
> elementListener =
> org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> BufferPool[4,096]
> BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
> monitoring
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> BufferPool@3
> BufferProvider.bufferCapacity = 4096
> BufferProvider.providedBuffers = 0
> BufferProvider.retainedBuffers = 0
> provider = BufferFactory[4,096]
> pooledBuffers = 0
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> TCPSelector
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPSelector@4
> selector = sun.nio.ch.KQueueSelectorImpl@9a029e
> clientOperations = serverOperations = thread = Thread[TCPSelector,5,main]
> running = true
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> TCPAcceptor[0.0.0.0:2,036]
> main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering server
> operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> server operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPAcceptor@5
> Acceptor.negotiator = null
> Acceptor.bufferProvider = BufferPool[4,096]
> Acceptor.protocolFactoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> Acceptor.protocolPostProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@5660d6
> Acceptor.lifecycleEventConverter =
> org.eclipse.internal.net4j.acceptor.Acceptor$1@ef83d3
> Acceptor.acceptedConnectors = selector = TCPSelector
> selectionKey = sun.nio.ch.SelectionKeyImpl@b40ec4
> startSynchronously = true
> synchronousStartTimeout = 4000
> startLatch = java.util.concurrent.CountDownLatch@faa550[Count = 0]
> serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
> address = 0.0.0.0
> port = 2036
>
> [INFO] Accepting connections: TCPAcceptor[0.0.0.0:2,036]
> Press any key to shutdown
>
>
> ===================== Server Trace ======================
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ManagedContainer
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> {org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
> tcp],
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default],
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo],
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp],
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default],
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp],
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]}
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> HashMapRegistry@1
> Registry.autoCommit = true
> Registry.transaction = null
> map =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ManagedContainer@2
> factoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> postProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> elementRegistry = maxElementID = 0
> elementListener =
> org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
>
> main [org.eclipse.internal.net4j.connector.Connector] Setting userID
> null for ClientTCPConnector[null:0]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> BufferPool[4,096]
> BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
> monitoring
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> BufferPool@3
> BufferProvider.bufferCapacity = 4096
> BufferProvider.providedBuffers = 0
> BufferProvider.retainedBuffers = 0
> provider = BufferFactory[4,096]
> pooledBuffers = 0
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> TCPSelector
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPSelector@4
> selector = sun.nio.ch.KQueueSelectorImpl@722456
> clientOperations = serverOperations = thread = Thread[TCPSelector,5,main]
> running = true
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ClientTCPConnector[localhost:2,036]
> main [org.eclipse.internal.net4j.connector.Connector] Setting state
> CONNECTING (was disconnected) for ClientTCPConnector[localhost:2,036]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> Channel[Control]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ChannelReceiveSerializer@5
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ChannelReceiveSerializer@5
> Worker.daemon = false
> Worker.activationTimeout = 2000
> Worker.deactivationTimeout = 2000
> Worker.activationLatch =
> java.util.concurrent.CountDownLatch@cebc9f[Count = 0]
> Worker.workerThread = Thread[ReceiveSerializer-1,5,main]
> QueueWorker.queue = QueueWorker.pollMillis = 100
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ControlChannel@6
> Channel.channelID = 0
> Channel.channelMultiplexer = ClientTCPConnector[localhost:2,036]
> Channel.channelIndex = -1
> Channel.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@1fc1a6
> Channel.receiveHandler = null
> Channel.receiveSerializer = ChannelReceiveSerializer@5
> Channel.sendQueue = registrations = SynchronizingCorrelator{}
>
> main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
> operation REGISTER java.nio.channels.SocketChannel[unconnected]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation REGISTER java.nio.channels.SocketChannel[unconnected]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Connecting
> java.nio.channels.SocketChannel[connection-pending
> remote=localhost/127.0.0.1:2036]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering
> client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering
> client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.internal.net4j.connector.Connector] Setting
> state CONNECTED (was connecting) for ClientTCPConnector[localhost:2,036]
> TCPSelector [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPClientConnector@7
> Connector.userID = null
> Connector.protocolFactoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> Connector.protocolPostProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> Connector.negotiator = null
> Connector.negotiationContext = null
> Connector.bufferProvider = BufferPool[4,096]
> Connector.receiveExecutor =
> java.util.concurrent.ThreadPoolExecutor@1fc1a6
> Connector.nextChannelID = 1
> Connector.channels = Connector.channelsLock =
> org.eclipse.net4j.util.concurrent.RWLock@15126e[Write locks = 0, Read
> locks = 0]
> Connector.connectorState = CONNECTED
> Connector.channelListener =
> org.eclipse.internal.net4j.connector.Connector$1@6d2380
> Connector.finishedConnecting =
> java.util.concurrent.CountDownLatch@35b1f3[Count = 1]
> Connector.finishedNegotiating =
> java.util.concurrent.CountDownLatch@35e6e3[Count = 1]
> TCPConnector.socketChannel = java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036]
> TCPConnector.selector = TCPSelector
> TCPConnector.selectionKey = sun.nio.ch.SelectionKeyImpl@a1c42f
> TCPConnector.writeQueue = TCPConnector.inputBuffer = null
> TCPConnector.controlChannel = Channel[Control]
> TCPConnector.host = localhost
> TCPConnector.port = 2036
>
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest (was connect)
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest READ
> main [org.eclipse.internal.net4j.connector.Connector] Waiting for
> connection...
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> SignalProtocol[echo]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> EchoClientProtocol@8
> Protocol.channel = Channel[-32,768]
> Protocol.bufferProvider = BufferPool[4,096]
> Protocol.executorService = java.util.concurrent.ThreadPoolExecutor@1fc1a6
> Protocol.infraStructure = null
> SignalProtocol.streamWrapper = null
> SignalProtocol.signals = SignalProtocol.nextCorrelationID = 1
>
> main [org.eclipse.internal.net4j.connector.Connector] Opening channel
> 0 with protocol echo
> main [org.eclipse.net4j.internal.tcp.ControlChannel] Registering
> channel 0 with protocol SignalProtocol[echo]
> main [org.eclipse.internal.net4j.buffer.BufferFactory] Created Buffer@9
> main [org.eclipse.internal.net4j.buffer.BufferPool] Obtained Buffer@9
> main [org.eclipse.internal.net4j.channel.Channel] Handling buffer from
> client: Buffer@9 --> Channel[Control]
> main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
> operation INTEREST WRITE java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest READ|WRITE (was read)
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Writing
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036]
> TCPSelector [org.eclipse.internal.net4j.buffer.Buffer] Writing 13 bytes
> 02 00 00 00 01 00 00 00 04 65 63 68 6f TCPSelector
> [org.eclipse.internal.net4j.buffer.BufferPool] Retaining Buffer@9
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering
> client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest READ (was read|write)
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating ManagedContainer
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating ClientTCPConnector[localhost:2,036]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating Channel[Control]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating ChannelReceiveSerializer@5
> main [org.eclipse.internal.net4j.connector.Connector] Setting state
> DISCONNECTED (was connected) for ClientTCPConnector[localhost:2,036]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating TCPSelector
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating BufferPool[4,096]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating
> {org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
> tcp],
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default],
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo],
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp],
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default],
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp],
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]}
> Exception in thread "main" BufferPoolMonitor
> [org.eclipse.internal.net4j.buffer.BufferPool] Stop monitoring
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
> at
> org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
>
> at
> org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
>
> at
> org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
>
>
>
>
>
>
|
|
|
| Re: [CDO] Client registration timeout exception [message #118360 is a reply to message #118265] |
Tue, 15 April 2008 05:39 |
| Eclipse User |
|
|
|
Originally posted by: ben.razzledazzle.gmail.com
Hi Eike,
A friend (who is much smarter than me) looked at this problem and has
discovered that on OS X the ordering of binding and registering of the
server socket makes a big difference. The binding should occur before the
registering on OSX.
He discovered this by using the code here:
http://www.exampledepot.com/egs/java.nio/NbServer.html
To test it, run the above NbServer code and then telnet into the socket
after the selector.select() is executed. If everything is working fine
then the telnet triggers the selector to wake and rest of the code is run.
When the binding occurs _before_ the registration everything works fine.
When the binding occurs _after_ the registration the selector.select()
never wakes up.
(This has been verified on two different machines)
So the Net4J, the problem occurs because the binding
(org.eclipse.net4j.internal.tcp.TCPAcceptor+handleRegistrati on) occurs
_after_ the registration
(org.eclipse.net4j.internal.tcp.TCPSelector+executeRegistrat ion).
This was confirmed when we did a quick hack in Net4J to change it so that
the binding occures _before_ the registration. After we did the
EchoServer worked correctly and so did the CDO server.
This is the hack:
In org.eclipse.net4j.internal.tcp.TCPSelector + executeRegistration was
changed so that the listener.handleRegistration is called twice:
- before the registration, so the binding can occur in the TCPAcceptor
- after the registration, so the selectionKey can be stored in the
TCPAcceptor
I also moved the trace so it is clear that the registration occurs after
the binding.
private void executeRegistration(final ServerSocketChannel channel,
final ITCPSelectorListener.Passive listener)
{
try
{
int interest = SelectionKey.OP_ACCEPT;
//*** NEW **//
listener.handleRegistration(null);
//************//
if (TRACER.isEnabled())
{
TRACER.trace("Registering " + channel); //$NON-NLS-1$
}
SelectionKey selectionKey = channel.register(selector, interest,
listener);
listener.handleRegistration(selectionKey);
}
catch (ClosedChannelException ex)
{
ex.printStackTrace();
OM.LOG.error(ex);
}
}
org.eclipse.net4j.internal.tcp.TCPAcceptor+ handleRegistration
- a check was added so that the selectionKey is set the second time the
method is called.
- a trace was added to show when the binding occured.
public void handleRegistration(SelectionKey selectionKey)
{
//*** NEW **//
if (this.selectionKey == null && selectionKey != null) {
this.selectionKey = selectionKey;
return;
}
//************//
try
{
InetSocketAddress addr = null;
if (address != null)
{
addr = new InetSocketAddress(InetAddress.getByName(address), port);
}
ServerSocket socket = serverSocketChannel.socket();
//*** NEW **//
if (TRACER.isEnabled())
{
TRACER.trace("Binding to server socket to address"); //$NON-NLS-1$
}
//************/
socket.bind(addr);
if (addr == null)
{
address = socket.getInetAddress().toString();
if (address.startsWith("/"))
{
address = address.substring(1);
}
int colon = address.indexOf(':');
if (colon != -1)
{
port = Integer.parseInt(address.substring(colon + 1));
address = address.substring(0, colon);
}
}
}
catch (Exception ex)
{
OM.LOG.error(ex);
deactivate();
}
finally
{
if (startLatch != null)
{
startLatch.countDown();
}
}
}
|
|
|
| Re: [CDO] Client registration timeout exception [message #118383 is a reply to message #118360] |
Tue, 15 April 2008 11:00 |
|
Hi Ben,
Great analysis! It would help me a lot if you could file a Bugzilla and
attach your changes as a patch against the latests HEAD of CVS. This way
you'll also be informed when I commit your patch ;-)
Cheers
/Eike
Ben C. wrote:
> Hi Eike,
> A friend (who is much smarter than me) looked at this problem and has
> discovered that on OS X the ordering of binding and registering of the
> server socket makes a big difference. The binding should occur before the
> registering on OSX.
> He discovered this by using the code here:
> http://www.exampledepot.com/egs/java.nio/NbServer.html
> To test it, run the above NbServer code and then telnet into the socket
> after the selector.select() is executed. If everything is working fine
> then the telnet triggers the selector to wake and rest of the code is run.
> When the binding occurs _before_ the registration everything works fine.
> When the binding occurs _after_ the registration the selector.select()
> never wakes up.
> (This has been verified on two different machines)
> So the Net4J, the problem occurs because the binding
> (org.eclipse.net4j.internal.tcp.TCPAcceptor+handleRegistrati on) occurs
> _after_ the registration
> (org.eclipse.net4j.internal.tcp.TCPSelector+executeRegistrat ion).
> This was confirmed when we did a quick hack in Net4J to change it so that
> the binding occures _before_ the registration. After we did the
> EchoServer worked correctly and so did the CDO server.
> This is the hack:
> In org.eclipse.net4j.internal.tcp.TCPSelector + executeRegistration was
> changed so that the listener.handleRegistration is called twice:
> - before the registration, so the binding can occur in the TCPAcceptor
> - after the registration, so the selectionKey can be stored in the
> TCPAcceptor
> I also moved the trace so it is clear that the registration occurs after
> the binding.
> private void executeRegistration(final ServerSocketChannel channel,
> final ITCPSelectorListener.Passive listener)
> {
> try
> {
> int interest = SelectionKey.OP_ACCEPT;
> //*** NEW **//
> listener.handleRegistration(null);
> //************//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Registering " + channel); //$NON-NLS-1$
> }
> SelectionKey selectionKey = channel.register(selector, interest,
> listener);
> listener.handleRegistration(selectionKey);
> }
> catch (ClosedChannelException ex)
> {
> ex.printStackTrace();
> OM.LOG.error(ex);
> }
> }
> org.eclipse.net4j.internal.tcp.TCPAcceptor+ handleRegistration
> - a check was added so that the selectionKey is set the second time the
> method is called.
> - a trace was added to show when the binding occured.
> public void handleRegistration(SelectionKey selectionKey)
> {
> //*** NEW **//
> if (this.selectionKey == null && selectionKey != null) {
> this.selectionKey = selectionKey;
> return;
> }
> //************//
> try
> {
> InetSocketAddress addr = null;
> if (address != null)
> {
> addr = new InetSocketAddress(InetAddress.getByName(address), port);
> }
> ServerSocket socket = serverSocketChannel.socket();
> //*** NEW **//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Binding to server socket to address"); //$NON-NLS-1$
> }
> //************/
> socket.bind(addr);
> if (addr == null)
> {
> address = socket.getInetAddress().toString();
> if (address.startsWith("/"))
> {
> address = address.substring(1);
> }
> int colon = address.indexOf(':');
> if (colon != -1)
> {
> port = Integer.parseInt(address.substring(colon + 1));
> address = address.substring(0, colon);
> }
> }
> }
> catch (Exception ex)
> {
> OM.LOG.error(ex);
> deactivate();
> }
> finally
> {
> if (startLatch != null)
> {
> startLatch.countDown();
> }
> }
> }
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
| Re: [CDO] Client registration timeout exception [message #119311 is a reply to message #118360] |
Sun, 20 April 2008 08:13 |
| Eclipse User |
|
|
|
Originally posted by: stepper.sympedia.de
Hi Ben,
I've refactored the registration protocol between TCPSelector and
TCPAcceptor/TCPConnector:
https://bugs.eclipse.org/bugs/show_bug.cgi?id=227880
Since I can't test it on Mac OS can you please confirm that the problem
is fixed?
Cheers
/Eike
Ben C. schrieb:
> Hi Eike,
> A friend (who is much smarter than me) looked at this problem and has
> discovered that on OS X the ordering of binding and registering of the
> server socket makes a big difference. The binding should occur before
> the registering on OSX.
>
> He discovered this by using the code here:
> http://www.exampledepot.com/egs/java.nio/NbServer.html
>
> To test it, run the above NbServer code and then telnet into the
> socket after the selector.select() is executed. If everything is
> working fine then the telnet triggers the selector to wake and rest of
> the code is run.
>
> When the binding occurs _before_ the registration everything works fine.
> When the binding occurs _after_ the registration the selector.select()
> never wakes up. (This has been verified on two different machines)
>
> So the Net4J, the problem occurs because the binding
> (org.eclipse.net4j.internal.tcp.TCPAcceptor+handleRegistrati on) occurs
> _after_ the registration
> (org.eclipse.net4j.internal.tcp.TCPSelector+executeRegistrat ion).
>
> This was confirmed when we did a quick hack in Net4J to change it so
> that the binding occures _before_ the registration. After we did the
> EchoServer worked correctly and so did the CDO server.
>
> This is the hack:
>
> In org.eclipse.net4j.internal.tcp.TCPSelector + executeRegistration
> was changed so that the listener.handleRegistration is called twice:
> - before the registration, so the binding can occur in the
> TCPAcceptor
> - after the registration, so the selectionKey can be stored in the
> TCPAcceptor
>
> I also moved the trace so it is clear that the registration occurs
> after the binding.
>
> private void executeRegistration(final ServerSocketChannel channel,
> final ITCPSelectorListener.Passive listener)
> {
> try
> {
> int interest = SelectionKey.OP_ACCEPT;
> //*** NEW **//
> listener.handleRegistration(null);
> //************//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Registering " + channel); //$NON-NLS-1$
> }
> SelectionKey selectionKey = channel.register(selector, interest,
> listener);
> listener.handleRegistration(selectionKey);
> }
> catch (ClosedChannelException ex)
> {
> ex.printStackTrace();
> OM.LOG.error(ex);
> }
> }
>
>
>
>
> org.eclipse.net4j.internal.tcp.TCPAcceptor+ handleRegistration
>
> - a check was added so that the selectionKey is set the second time
> the method is called. - a trace was added to show when the binding
> occured.
>
> public void handleRegistration(SelectionKey selectionKey)
> {
> //*** NEW **//
> if (this.selectionKey == null && selectionKey != null) {
> this.selectionKey = selectionKey;
> return; }
> //************//
> try
> {
> InetSocketAddress addr = null;
> if (address != null)
> {
> addr = new InetSocketAddress(InetAddress.getByName(address),
> port);
> }
>
> ServerSocket socket = serverSocketChannel.socket();
> //*** NEW **//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Binding to server socket to address"); //$NON-NLS-1$
> }
> //************/
> socket.bind(addr);
>
> if (addr == null)
> {
> address = socket.getInetAddress().toString();
> if (address.startsWith("/"))
> {
> address = address.substring(1);
> }
>
> int colon = address.indexOf(':');
> if (colon != -1)
> {
> port = Integer.parseInt(address.substring(colon + 1));
> address = address.substring(0, colon);
> }
> }
> }
> catch (Exception ex)
> {
> OM.LOG.error(ex);
> deactivate();
> }
> finally
> {
> if (startLatch != null)
> {
> startLatch.countDown();
> }
> }
> }
>
>
>
>
>
|
|
|
| Re: [CDO] Client registration timeout exception [message #616274 is a reply to message #118189] |
Mon, 14 April 2008 07:57 |
|
Hi Ben,
Comments inline...
Ben schrieb:
> I'm new to CDO and I'm trying to connect to a CDO server using the
> "CDO Sessions View"
> (org.eclipse.emf.cdo.CDOSession.CDOSessionsView). Here is rundown of
> what I'm doing:
>
> - JVM 1.5.0 (using OS X) , Eclipse 3.4m5,
> - I run a CDO server using the product configuration
> org.eclipse.emf.cdo.server.product.
> - I run an eclipse workbench configuration with the following
> additional plugins:
> org.eclipse.emf.cdo (0.8.0)
> org.eclipse.emf.cdo.edit (0.8.0)
> org.eclipse.emf.cdo.protocol (0.8.0)
> org.eclipse.emf.cdo.ui (0.8.0)
> org.eclipse.emf.net4j (0.8.0)
> org.eclipse.emf.net4j.db (0.8.0)
> org.eclipse.emf.net4j.db.derby (0.8.0)
> org.eclipse.emf.net4j.tcp (0.8.0) org.eclipse.emf.net4j.util
> (0.8.0)
> org.eclipse.emf.net4j.util.ui (0.8.0)
> (and other emf 2.4 plugins)
All of the 0.8.0 builds are integration builds and breaking changes can
occur at any time. Thus you must ensure that server and client plugins
come from the same build!
> - In the CDO sessions view, I try to open a session using the dialog.
> (Server - tcp://localhost:2036, Repository Name - repo, Legacy Support
> checkbox is disabled and not checked)
>
> - After a wait a dialog box comes up with "Unable to open a session on
> the specified repository
> tcp://localhost:2036/repo?disableLegacyObjects=true"
>
> - A registration error is occuring in the client
> (org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel):
>
> [ERROR] Registration timeout after 10000 milliseconds
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
>
>
> - I've extended (and also disabled) the CDO timeout values but this
> hasn't resulted in a registration.
> - The client and server traces and cdo-server.xml are included below.
> If needed I can access the ClientTCPConnector using the Introspector
> view to retrieve any required information.
> Any help would be appreciated.
Your configurations seem to be ok.
Here on my Windows box everything works as expected.
Maybe it's a Mac OS related issue which I fear I can't debug here ;-(
Is your problem reproducible?
The logs that you pasted look ok up to the point with the client exception.
Maybe you can start debugging at a lower and simpler level.
I just committed a pure Net4j example. Can you please verify that the
ECHOProtocol is able to run on Mac OS?
- org.eclipse.net4j.examples.echo.server.EchoServer
- org.eclipse.net4j.examples.echo.client.EchoClient
When you want to debug your setup I suggest that you start somewhere in
- org.eclipse.net4j.internal.tcp.TCPAcceptor.handleAccept(ITCP Selector,
ServerSocketChannel)
- org.eclipse.internal.net4j.connector.Connector.createChannel (int,
short, String)
Sorry, as long as there is no exception in the trace (of the server
side) or I can reproduce the problem here it's hard to find the cause ;-(
Cheers
/Eike
>
> =========================== cdo-server.xml ====================
>
> <?xml version="1.0" encoding="UTF-8"?>
> <cdoServer>
>
>
> <acceptor type="tcp" listenAddr="0.0.0.0" port="2036">
> <!--
> <negotiator type="challenge" description="/temp/users.db"/> -->
> </acceptor>
>
> <repository name="repo">
> <property name="overrideUUID"
> value="1ff5d226-b1f0-40fb-aba2-0c31b38c764f"/>
> <property name="supportingAudits" value="true"/>
> <property name="verifyingRevisions" value="false"/>
> <property name="rememberingKnownTypes" value="false"/>
The above property is not supported anymore. You can remove it (although
this doesn't cause your problem)
> <property name="currentLRUCapacity" value="10000"/>
> <property name="revisedLRUCapacity" value="100"/>
> <store type="db">
> <!-- type: horizontal | vertical | <any user-contributed type>-->
> <mappingStrategy type="horizontal">
> <!-- ONE_TABLE_PER_REFERENCE | ONE_TABLE_PER_CLASS |
> ONE_TABLE_PER_PACKAGE | ONE_TABLE_PER_REPOSITORY | LIKE_ATTRIBUTES -->
> <property name="toManyReferences"
> value="ONE_TABLE_PER_REFERENCE"/>
>
> <!-- LIKE_ATTRIBUTES | LIKE_TO_MANY_REFERENCES-->
> <property name="toOneReferences" value="LIKE_ATTRIBUTES"/>
> <!-- MODEL | STRATEGY-->
> <property name="mappingPrecedence" value="MODEL"/>
> </mappingStrategy>
> <dbAdapter name="derby"/>
> <dataSource class="org.apache.derby.jdbc.EmbeddedDataSource"
> databaseName="/cdodb"
> createDatabase="create"/>
>
> <!-- <dbAdapter name="derby"/>
> <dataSource class="org.apache.derby.jdbc.ClientDataSource"
> databaseName="cdodb"
> createDatabase="create"/>-->
>
> <!--<dbAdapter name="hsqldb"/>
> <dataSource class="org.eclipse.net4j.db.hsqldb.HSQLDBDataSource"
> database="jdbc:hsqldb:mem:cdodb1"
> user="sa"/>-->
>
> <!--<dbAdapter name="mysql"/>
> <dataSource class="com.mysql.jdbc.jdbc2.optional.MysqlDataSource"
> url="jdbc:mysql://localhost/cdodb1"
> user="sa"/>-->
> </store>
> </repository>
>
> </cdoServer>
>
> =========================== Server Trace
> ========================
>
>
>
> Configuration location:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
> Reduced/
> Configuration file:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
> Reduced/config.ini loaded
> Install location:
> file:/Applications/eclipse 3.4/eclipse/
> Framework located:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Framework classpath:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Splash location:
> null
> Debug options:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Server
> Reduced/.options loaded
>
> osgi> Time to load bundles: 483
> Starting application: 3526
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j.util
> Thread-0 [debug.lifecycle] Activating ManagedContainer
> Thread-0 [debug.lifecycle] Activating {}
> Thread-0 [debug.lifecycle.dump] DUMP PluginFactoryRegistry@1
> Registry.autoCommit = true
> Registry.transaction = null
> HashMapRegistry.map =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
> file]
>
> org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
> challenge]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
> cdo]
> extensionRegistryListener =
> org.eclipse.net4j.internal.util.factory.PluginFactoryRegistr y$1@12ce69
>
> Thread-0 [debug.lifecycle] Activating []
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j.tcp
> Thread-0 [debug.lifecycle.dump] DUMP PluginElementProcessorList@2
> processors =
> org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
>
> org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
> extensionRegistryListener =
> org.eclipse.net4j.internal.util.container.PluginElementProce ssorList$1@594680
>
>
> Thread-0 [debug.lifecycle.dump] DUMP PluginContainer@3
> ManagedContainer.factoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
> file]
>
> org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
> challenge]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
> cdo]
> ManagedContainer.postProcessors =
> org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
>
> org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
> ManagedContainer.elementRegistry = ManagedContainer.maxElementID = 0
> ManagedContainer.elementListener =
> org.eclipse.net4j.internal.util.container.ManagedContainer$1@d6c8b9
>
> Thread-0 [debug.om] Plugin container created: ManagedContainer
> Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.server
> Thread-0 [debug.om] Starting application org.eclipse.emf.cdo.server.app
> [INFO] CDO Server starting
> Thread-0 [debug.repository] Configuring CDO server from workspace/CDO
> Server/server/config/cdo-server.xml
> Thread-0 [debug.repository] Configuring repository repo (type=default)
> Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.protocol
> Thread-0 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Thread-0 [debug.model] Created CDOClass(ID=0, name=CDOObject)
> Thread-0 [debug.model] Adding class: CDOClass(ID=0, name=CDOObject)
> Thread-0 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Thread-0 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Thread-0 [debug.model] Created CDOClass(ID=0, name=CDOResource)
> Thread-0 [debug.model] Created CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Thread-0 [debug.model] Adding feature: CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Thread-0 [debug.model] Created CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Thread-0 [debug.model] Adding feature: CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Thread-0 [debug.model] Adding class: CDOClass(ID=0, name=CDOResource)
> Thread-0 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Thread-0 [debug.om] Starting bundle org.eclipse.emf.cdo.server.db
> Thread-0 [debug.om] Starting bundle org.eclipse.net4j.db
> Thread-0 [debug.lifecycle] Activating Repository[repo, null]
> Thread-0 [debug.lifecycle] Activating DBStore@4
> Thread-0 [debug.sql] CREATE TABLE cdo_classes (id INTEGER, package
> INTEGER, classifier INTEGER, name VARCHAR(255), abstract SMALLINT)
> Thread-0 [debug.sql] -- Table/View 'CDO_CLASSES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_supertypes (type_id INTEGER,
> supertype_package VARCHAR(255), supertype_classifier INTEGER)
> Thread-0 [debug.sql] -- Table/View 'CDO_SUPERTYPES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_features (id INTEGER, class
> INTEGER, feature INTEGER, name VARCHAR(255), type INTEGER,
> reference_package VARCHAR(255), reference_classifier INTEGER, many
> SMALLINT, containment SMALLINT, idx INTEGER)
> Thread-0 [debug.sql] -- Table/View 'CDO_FEATURES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_repository (name VARCHAR(255),
> uuid VARCHAR(64), starts BIGINT, started BIGINT, stopped BIGINT,
> next_cdoid BIGINT, next_metaid BIGINT)
> Thread-0 [debug.sql] -- Table/View 'CDO_REPOSITORY' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] CREATE TABLE cdo_packages (id INTEGER, uri
> VARCHAR(255), name VARCHAR(255), ecore CLOB, dynamic SMALLINT,
> range_lb BIGINT, range_ub BIGINT)
> Thread-0 [debug.sql] -- Table/View 'CDO_PACKAGES' already exists in
> Schema 'APP'.
> Thread-0 [debug.sql] SELECT MAX(next_cdoid) FROM cdo_repository
> Thread-0 [debug.sql] SELECT MAX(next_metaid) FROM cdo_repository
> Thread-0 [debug.sql] UPDATE cdo_repository SET starts=starts+1,
> started=1208142625647, stopped=0, next_cdoid=-1, next_metaid=-1
> Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_packages
> Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_classes
> Thread-0 [debug.sql] SELECT MAX(id) FROM cdo_features
> Thread-0 [debug.lifecycle] Activating horizontal
> Thread-0 [debug.lifecycle] Activating ObjectTypeCache@5
> Thread-0 [debug.lifecycle.dump] DUMP ObjectTypeCache@5
> mappingStrategy = horizontal
> table = null
> idField = null
> typeField = null
> initializeLock = java.lang.Object@70f15e
>
> Thread-0 [debug.lifecycle.dump] DUMP HorizontalMappingStrategy@6
> MappingStrategy.store = DBStore@4
> MappingStrategy.properties = toOneReferences=LIKE_ATTRIBUTES
> toManyReferences=ONE_TABLE_PER_REFERENCE
> mappingPrecedence=MODEL
> MappingStrategy.referenceTables = MappingStrategy.classRefs =
> MappingStrategy.resourceClassMapping = null
> MappingStrategy.resourcePathMapping = null
> MappingStrategy.resourceTable = null
> MappingStrategy.resourceIDField = null
> MappingStrategy.resourcePathField = null
> objectTypeCache = ObjectTypeCache@5
>
> Thread-0 [debug.lifecycle.dump] DUMP DBStore@4
> Store.type = db
> Store.properties = null
> Store.repository = Repository[repo, null]
> LongIDStore.lastObjectID = 2
> mappingStrategy = horizontal
> dbSchema = null
> dbAdapter = derby-10.2.2.0
> dbConnectionProvider = org.apache.derby.jdbc.EmbeddedDataSource@a91761
> nextPackageID = 1
> nextClassID = 1
> nextFeatureID = 1
>
> Thread-0 [debug.lifecycle] Activating PackageManager@7
> Thread-0 [debug.sql] SELECT uri, dynamic, range_lb, range_ub FROM
> cdo_packages
> Thread-0 [debug.lifecycle.dump] DUMP PackageManager@7
> CDOPackageManagerImpl.packages =
> http://www.eclipse.org/emf/CDO/core/1.0.0=CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
>
> http://www.eclipse.org/emf/CDO/resource/1.0.0=CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> CDOPackageManagerImpl.cdoCorePackage =
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> CDOPackageManagerImpl.cdoResourcePackage =
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> repository = Repository[repo, null]
>
> Thread-0 [debug.lifecycle] Activating SessionManager@8
> Thread-0 [debug.lifecycle.dump] DUMP SessionManager@8
> repository = Repository[repo, null]
> sessions = lastSessionID = 0
>
> Thread-0 [debug.lifecycle] Activating ResourceManager@9
> Thread-0 [debug.lifecycle.dump] DUMP ResourceManager@9
> repository = Repository[repo, null]
> idToPathMap = pathToIDMap =
> Thread-0 [debug.lifecycle] Activating RevisionManager@10
> Thread-0 [debug.lifecycle.dump] DUMP RevisionManager@10
> CDORevisionResolverImpl.revisions =
> CDORevisionResolverImpl.currentLRUCapacity = 10000
> CDORevisionResolverImpl.revisedLRUCapacity = 100
> CDORevisionResolverImpl.currentLRU = LRU[size=0, capacity=10,000]
> CDORevisionResolverImpl.revisedLRU = LRU[size=0, capacity=100]
> repository = Repository[repo, null]
> cdoPathFeature = CDOFeature(ID=9, name=path, type=STRING,
> referenceType=null)
>
> Thread-0 [debug.lifecycle.dump] DUMP Repository@11
> name = repo
> store = DBStore@4
> uuid = null
> properties = revisedLRUCapacity=100
> rememberingKnownTypes=false
> supportingAudits=true
> verifyingRevisions=false
> overrideUUID=1ff5d226-b1f0-40fb-aba2-0c31b38c764f
> currentLRUCapacity=10000
> supportingRevisionDeltas = null
> supportingAudits = true
> verifyingRevisions = null
> packageManager = PackageManager@7
> sessionManager = SessionManager@8
> resourceManager = ResourceManager@9
> revisionManager = RevisionManager@10
> elements = [Lorg.eclipse.emf.cdo.server.IRepositoryElement;@10609a
> lastMetaID = 0
>
> Thread-0 [debug] Configuring Net4j server from workspace/CDO
> Server/server/config/cdo-server.xml
> Thread-0 [debug.lifecycle] Activating BufferPool[4,096]
> BufferPoolMonitor [debug.buffer] Start monitoring
> Thread-0 [debug.lifecycle.dump] DUMP BufferPool@12
> BufferProvider.bufferCapacity = 4096
> BufferProvider.providedBuffers = 0
> BufferProvider.retainedBuffers = 0
> provider = BufferFactory[4,096]
> pooledBuffers = 0
>
> Thread-0 [debug.lifecycle] Activating TCPSelector
> Thread-0 [debug.lifecycle.dump] DUMP TCPSelector@13
> selector = sun.nio.ch.KQueueSelectorImpl@c20307
> clientOperations = serverOperations = thread = Thread[TCPSelector,5,main]
> running = true
>
> Thread-0 [debug.lifecycle] Activating TCPAcceptor[0.0.0.0:2,036]
> Thread-0 [debug] Ordering server operation REGISTER
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [debug] Executing server operation REGISTER
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [debug] Registering
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> Thread-0 [debug.lifecycle.dump] DUMP TCPAcceptor@14
> Acceptor.negotiator = null
> Acceptor.bufferProvider = BufferPool[4,096]
> Acceptor.protocolFactoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.userManagers[file]=Factory[org.eclipse.net 4j.userManagers,
> file]
>
> org.eclipse.net4j.Negotiators[challenge]=Factory[org.eclipse .net4j.Negotiators,
> challenge]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> org.eclipse.net4j.serverProtocols[cdo]=Factory[org.eclipse.n et4j.serverProtocols,
> cdo]
> Acceptor.protocolPostProcessors =
> org.eclipse.net4j.internal.util.security.ChallengeNegotiator Configurer @31ac05
>
> org.eclipse.internal.net4j.Net4jTransportInjector@1492ed
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@ba3f9a
> Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@c6482
> Acceptor.lifecycleEventConverter =
> org.eclipse.internal.net4j.acceptor.Acceptor$1@9ab21d
> Acceptor.acceptedConnectors = selector = TCPSelector
> selectionKey = sun.nio.ch.SelectionKeyImpl@85a317
> startSynchronously = true
> synchronousStartTimeout = 4000
> startLatch = java.util.concurrent.CountDownLatch@af3479[Count = 0]
> serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
> address = 0.0.0.0
> port = 2036
>
> [INFO] CDO Server started
> Application Started: 14098
>
>
>
> =========================== Client Trace
> ========================
>
>
> Configuration location:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
> Workspace/
> Configuration file:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
> Workspace/config.ini loaded
> Install location:
> file:/Applications/eclipse 3.4/eclipse/
> Framework located:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Framework classpath:
> file:/Applications/eclipse
> 3.4/eclipse/plugins/org.eclipse.osgi_3.4.0.v20080205.jar
> Debug options:
> file:workspace/.metadata/.plugins/org.eclipse.pde.core/CDO Client
> Workspace/.options loaded
>
> osgi> Time to load bundles: 25
> Starting application: 2843
> Application Started: 13665
> [INFO] Legacy system not available
> Worker-4 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Created CDOClass(ID=0, name=CDOObject)
> Worker-4 [debug.model] Adding class: CDOClass(ID=0, name=CDOObject)
> Worker-4 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Created
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Created CDOClass(ID=0, name=CDOResource)
> Worker-4 [debug.model] Created CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Worker-4 [debug.model] Adding feature: CDOFeature(ID=9, name=path,
> type=STRING, referenceType=null)
> Worker-4 [debug.model] Created CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Worker-4 [debug.model] Adding feature: CDOFeature(ID=2, name=contents,
> type=OBJECT, referenceType=CDOClass(ID=0, name=CDOObject))
> Worker-4 [debug.model] Adding class: CDOClass(ID=0, name=CDOResource)
> Worker-4 [debug.model] Added package:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null)
> Worker-4 [debug.model] Setting client info:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/core/1.0.0,
> name=cdocore, dynamic=false, metaIDRange=null) -->
> org.eclipse.emf.ecore.impl.EcorePackageImpl@c76d78 (name: ecore)
> (nsURI: http://www.eclipse.org/emf/2002/Ecore, nsPrefix: ecore)
> Worker-4 [debug.model] Setting client info: CDOClass(ID=0,
> name=CDOObject) --> org.eclipse.emf.ecore.impl.EClassImpl@e3afa9
> (name: EObject) (instanceClassName: null) (abstract: false, interface:
> false)
> Worker-4 [debug.model] Setting client info:
> CDOPackage(URI=http://www.eclipse.org/emf/CDO/resource/1.0.0,
> name=cdoresource, dynamic=false, metaIDRange=null) -->
> org.eclipse.emf.cdo.eresource.impl.EresourcePackageImpl@bc80d8 (name:
> eresource) (nsURI: http://www.eclipse.org/emf/CDO/resource/1.0.0,
> nsPrefix: eresource)
> Worker-4 [debug.model] Setting client info: CDOClass(ID=0,
> name=CDOResource) --> org.eclipse.emf.ecore.impl.EClassImpl@1033db
> (name: CDOResource) (instanceClassName: null) (abstract: false,
> interface: false)
> Worker-4 [debug.model] Setting client info: CDOFeature(ID=2,
> name=contents, type=OBJECT, referenceType=CDOClass(ID=0,
> name=CDOObject)) --> org.eclipse.emf.ecore.impl.EReferenceImpl@ad3677
> (name: contents) (ordered: true, unique: true, lowerBound: 0,
> upperBound: -1) (changeable: true, volatile: false, transient: false,
> defaultValueLiteral: null, unsettable: false, derived: false)
> (containment: true, resolveProxies: false)
> Worker-4 [debug.model] Setting client info: CDOFeature(ID=9,
> name=path, type=STRING, referenceType=null) -->
> org.eclipse.emf.ecore.impl.EAttributeImpl@d2eead (name: path)
> (ordered: true, unique: true, lowerBound: 0, upperBound: 1)
> (changeable: true, volatile: false, transient: false,
> defaultValueLiteral: null, unsettable: false, derived: false) (iD: false)
> Worker-4 [debug.connector] Setting userID null for
> ClientTCPConnector[null:0]
> BufferPoolMonitor [debug.buffer] Start monitoring
> BufferPoolMonitor [debug.buffer] Stop monitoring
> Worker-4 [debug.connector] Setting state CONNECTING (was disconnected)
> for ClientTCPConnector[localhost:2,036]
> Worker-4 [debug] Ordering client operation REGISTER
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [debug] Executing client operation REGISTER
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [debug] Registering
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [debug] Connecting
> java.nio.channels.SocketChannel[connection-pending
> remote=localhost/127.0.0.1:2036]
> TCPSelector [debug] Ordering client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Ordering client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug.connector] Setting state CONNECTED (was connecting)
> for ClientTCPConnector[localhost:2,036]
> TCPSelector [debug] Executing client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Setting interest (was connect)
> TCPSelector [debug] Executing client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug] Setting interest READ
> Worker-4 [debug.connector] Waiting for connection...
> Worker-4 [debug.connector] Opening channel 0 with protocol cdo
> Worker-4 [debug] Registering channel 0 with protocol SignalProtocol[cdo]
> Worker-4 [debug.buffer] Created Buffer@1
> Worker-4 [debug.buffer] Obtained Buffer@1
> Worker-4 [debug.channel] Handling buffer from client: Buffer@1 -->
> Channel[Control]
> Worker-4 [debug] Ordering client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug] Executing client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [debug] Setting interest READ|WRITE (was read)
> TCPSelector [debug] Writing java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:51054 remote=localhost/127.0.0.1:2036]
> TCPSelector [debug.buffer] Writing 12 bytes
> 02 00 00 00 01 00 00 00 03 63 64 6f TCPSelector [debug.buffer]
> Retaining Buffer@1
> TCPSelector [debug] Ordering client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Executing client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:51054
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [debug] Setting interest READ (was read|write)
> [ERROR] Registration timeout after 10000 milliseconds
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
> at
> org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
>
> at
> org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
>
> at
> org.eclipse.emf.internal.cdo.CDOSessionImpl.doActivate(CDOSe ssionImpl.java:623)
>
> at
> org.eclipse.net4j.internal.util.lifecycle.Lifecycle.activate (Lifecycle.java:57)
>
> at
> org.eclipse.net4j.util.lifecycle.LifecycleUtil.activate(Life cycleUtil.java:71)
>
> at
> org.eclipse.net4j.util.lifecycle.LifecycleUtil.activate(Life cycleUtil.java:61)
>
> at
> org.eclipse.net4j.internal.util.container.ManagedContainer.g etElement(ManagedContainer.java:260)
>
> at
> org.eclipse.emf.cdo.internal.ui.actions.OpenSessionAction.do Run(OpenSessionAction.java:70)
>
> at
> org.eclipse.net4j.util.ui.actions.LongRunningAction$1.run(Lo ngRunningAction.java:164)
>
> at
> org.eclipse.net4j.util.om.monitor.MonitoredJob.run(Monitored Job.java:48)
> at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
>
>
>
>
>
>
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
| Re: [CDO] Client registration timeout exception [message #616278 is a reply to message #118223] |
Mon, 14 April 2008 09:20 |
 Ben
Messages: 46
Registered: July 2009 |
Member |
|
|
Thanks for the prompt reply Eike.
- I've run the EchoClient example and I have the same error. I've
included the client and server trace below.
- For clarification, I'm running what is currently in CVS for net4j and
cdo.
- Are you using the Java SE 6? Have you tried it using Java SE 5
instead? (that is what I'm using since Java SE 6 hasn't been released on
OS X yet)
I'm debugging from the points you said but it comes back to
- org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel catching
the exception:
Exception in thread "main"
org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Registration
timeout after 10000 milliseconds
at
org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
at
org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
at
org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
- org.eclipse.net4j.internal.util.concurrent .ResultSynchronizer # public
RESULT get(long timeout) always returns a null RESULT.
- org.eclipse.net4j.internal.tcp.TCPAcceptor.handleAccept(ITCP Selector,
ServerSocketChannel) is never called.
==================== Server Trace ====================
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ManagedContainer
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
{org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
tcp],
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default],
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp],
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default],
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo],
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp],
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]}
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
HashMapRegistry@1
Registry.autoCommit = true
Registry.transaction = null
map =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ManagedContainer@2
factoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
postProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
elementRegistry =
maxElementID = 0
elementListener =
org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
BufferPool[4,096]
BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
monitoring
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
BufferPool@3
BufferProvider.bufferCapacity = 4096
BufferProvider.providedBuffers = 0
BufferProvider.retainedBuffers = 0
provider = BufferFactory[4,096]
pooledBuffers = 0
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
TCPSelector
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPSelector@4
selector = sun.nio.ch.KQueueSelectorImpl@9a029e
clientOperations =
serverOperations =
thread = Thread[TCPSelector,5,main]
running = true
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
TCPAcceptor[0.0.0.0:2,036]
main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering server
operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing server
operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
sun.nio.ch.ServerSocketChannelImpl[unbound]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPAcceptor@5
Acceptor.negotiator = null
Acceptor.bufferProvider = BufferPool[4,096]
Acceptor.protocolFactoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
echo]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
Acceptor.protocolPostProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@5660d6
Acceptor.lifecycleEventConverter =
org.eclipse.internal.net4j.acceptor.Acceptor$1@ef83d3
Acceptor.acceptedConnectors =
selector = TCPSelector
selectionKey = sun.nio.ch.SelectionKeyImpl@b40ec4
startSynchronously = true
synchronousStartTimeout = 4000
startLatch = java.util.concurrent.CountDownLatch@faa550[Count = 0]
serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
address = 0.0.0.0
port = 2036
[INFO] Accepting connections: TCPAcceptor[0.0.0.0:2,036]
Press any key to shutdown
===================== Server Trace ======================
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ManagedContainer
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
{org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
tcp],
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default],
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo],
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp],
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default],
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp],
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]}
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
HashMapRegistry@1
Registry.autoCommit = true
Registry.transaction = null
map =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ManagedContainer@2
factoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
postProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
elementRegistry =
maxElementID = 0
elementListener =
org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
main [org.eclipse.internal.net4j.connector.Connector] Setting userID null
for ClientTCPConnector[null:0]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
BufferPool[4,096]
BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
monitoring
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
BufferPool@3
BufferProvider.bufferCapacity = 4096
BufferProvider.providedBuffers = 0
BufferProvider.retainedBuffers = 0
provider = BufferFactory[4,096]
pooledBuffers = 0
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
TCPSelector
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPSelector@4
selector = sun.nio.ch.KQueueSelectorImpl@722456
clientOperations =
serverOperations =
thread = Thread[TCPSelector,5,main]
running = true
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ClientTCPConnector[localhost:2,036]
main [org.eclipse.internal.net4j.connector.Connector] Setting state
CONNECTING (was disconnected) for ClientTCPConnector[localhost:2,036]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
Channel[Control]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
ChannelReceiveSerializer@5
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ChannelReceiveSerializer@5
Worker.daemon = false
Worker.activationTimeout = 2000
Worker.deactivationTimeout = 2000
Worker.activationLatch = java.util.concurrent.CountDownLatch@cebc9f[Count
= 0]
Worker.workerThread = Thread[ReceiveSerializer-1,5,main]
QueueWorker.queue =
QueueWorker.pollMillis = 100
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
ControlChannel@6
Channel.channelID = 0
Channel.channelMultiplexer = ClientTCPConnector[localhost:2,036]
Channel.channelIndex = -1
Channel.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@1fc1a6
Channel.receiveHandler = null
Channel.receiveSerializer = ChannelReceiveSerializer@5
Channel.sendQueue =
registrations = SynchronizingCorrelator{}
main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation REGISTER java.nio.channels.SocketChannel[unconnected]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation REGISTER java.nio.channels.SocketChannel[unconnected]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
java.nio.channels.SocketChannel[unconnected]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Connecting
java.nio.channels.SocketChannel[connection-pending
remote=localhost/127.0.0.1:2036]
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST CONNECT java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST READ java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.internal.net4j.connector.Connector] Setting state
CONNECTED (was connecting) for ClientTCPConnector[localhost:2,036]
TCPSelector [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
TCPClientConnector@7
Connector.userID = null
Connector.protocolFactoryRegistry =
org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
tcp]
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default]
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo]
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp]
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default]
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp]
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]
Connector.protocolPostProcessors =
org.eclipse.internal.net4j.Net4jTransportInjector@82764b
org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
Connector.negotiator = null
Connector.negotiationContext = null
Connector.bufferProvider = BufferPool[4,096]
Connector.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@1fc1a6
Connector.nextChannelID = 1
Connector.channels =
Connector.channelsLock =
org.eclipse.net4j.util.concurrent.RWLock@15126e[Write locks = 0, Read
locks = 0]
Connector.connectorState = CONNECTED
Connector.channelListener =
org.eclipse.internal.net4j.connector.Connector$1@6d2380
Connector.finishedConnecting =
java.util.concurrent.CountDownLatch@35b1f3[Count = 1]
Connector.finishedNegotiating =
java.util.concurrent.CountDownLatch@35e6e3[Count = 1]
TCPConnector.socketChannel = java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036]
TCPConnector.selector = TCPSelector
TCPConnector.selectionKey = sun.nio.ch.SelectionKeyImpl@a1c42f
TCPConnector.writeQueue =
TCPConnector.inputBuffer = null
TCPConnector.controlChannel = Channel[Control]
TCPConnector.host = localhost
TCPConnector.port = 2036
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST CONNECT java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
(was connect)
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST READ java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
READ
main [org.eclipse.internal.net4j.connector.Connector] Waiting for
connection...
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
SignalProtocol[echo]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
EchoClientProtocol@8
Protocol.channel = Channel[-32,768]
Protocol.bufferProvider = BufferPool[4,096]
Protocol.executorService = java.util.concurrent.ThreadPoolExecutor@1fc1a6
Protocol.infraStructure = null
SignalProtocol.streamWrapper = null
SignalProtocol.signals =
SignalProtocol.nextCorrelationID = 1
main [org.eclipse.internal.net4j.connector.Connector] Opening channel 0
with protocol echo
main [org.eclipse.net4j.internal.tcp.ControlChannel] Registering channel 0
with protocol SignalProtocol[echo]
main [org.eclipse.internal.net4j.buffer.BufferFactory] Created Buffer@9
main [org.eclipse.internal.net4j.buffer.BufferPool] Obtained Buffer@9
main [org.eclipse.internal.net4j.channel.Channel] Handling buffer from
client: Buffer@9 --> Channel[Control]
main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
READ|WRITE (was read)
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Writing
java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
remote=localhost/127.0.0.1:2036]
TCPSelector [org.eclipse.internal.net4j.buffer.Buffer] Writing 13 bytes
02 00 00 00 01 00 00 00 04 65 63 68 6f
TCPSelector [org.eclipse.internal.net4j.buffer.BufferPool] Retaining
Buffer@9
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing client
operation INTEREST WRITE java.nio.channels.SocketChannel[connected
local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = false
TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting interest
READ (was read|write)
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
ManagedContainer
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
ClientTCPConnector[localhost:2,036]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
Channel[Control]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
ChannelReceiveSerializer@5
main [org.eclipse.internal.net4j.connector.Connector] Setting state
DISCONNECTED (was connected) for ClientTCPConnector[localhost:2,036]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
TCPSelector
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
BufferPool[4,096]
main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Deactivating
{org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
tcp],
org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
default],
org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
echo],
org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
tcp],
org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
default],
org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
tcp],
org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
default]}
Exception in thread "main" BufferPoolMonitor
[org.eclipse.internal.net4j.buffer.BufferPool] Stop monitoring
org.eclipse.net4j.util.concurrent.TimeoutRuntimeException: Registration
timeout after 10000 milliseconds
at
org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
at
org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
at
org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
at
org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
|
|
|
| Re: [CDO] Client registration timeout exception [message #616283 is a reply to message #118239] |
Mon, 14 April 2008 09:47 |
|
Ben schrieb:
> Thanks for the prompt reply Eike.
>
> - I've run the EchoClient example and I have the same error. I've
> included the client and server trace below.
Ok, so we should concentrate on this simple example.
The traces don't show anything new ;-(
>
> - For clarification, I'm running what is currently in CVS for net4j
> and cdo.
That's good.
> - Are you using the Java SE 6? Have you tried it using Java SE 5
> instead? (that is what I'm using since Java SE 6 hasn't been released
> on OS X yet)
All plugins are developed against JSE-1.5 and tested on windows and linux.
More and more I tend to believe that this is related to issues with Mac
OS handling of sockets and selectors...
>
> I'm debugging from the points you said but it comes back to -
> org.eclipse.net4j.internal.tcp.ControlChannel # registerChannel
> catching the exception:
> Exception in thread "main"
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
> at
> org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
>
> at
> org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
>
> at
> org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
>
>
>
> - org.eclipse.net4j.internal.util.concurrent .ResultSynchronizer #
> public RESULT get(long timeout) always returns a null RESULT.
> -
> org.eclipse.net4j.internal.tcp.TCPAcceptor.handleAccept(ITCP Selector,
> ServerSocketChannel) is never called.
The latter indicates that incoming connection requests are not recognized.
Again, I can't help you on Mac OS, even though I really would like to.
In TCPSelector there are a few catch blocks which don't trace
exceptions. You could add some ex.printStackTrace() there and see what
happens.
Cheers
/Eike
>
> ==================== Server Trace ====================
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ManagedContainer
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> {org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
> tcp],
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default],
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp],
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default],
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo],
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp],
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]}
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> HashMapRegistry@1
> Registry.autoCommit = true
> Registry.transaction = null
> map =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ManagedContainer@2
> factoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> postProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> elementRegistry = maxElementID = 0
> elementListener =
> org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> BufferPool[4,096]
> BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
> monitoring
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> BufferPool@3
> BufferProvider.bufferCapacity = 4096
> BufferProvider.providedBuffers = 0
> BufferProvider.retainedBuffers = 0
> provider = BufferFactory[4,096]
> pooledBuffers = 0
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> TCPSelector
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPSelector@4
> selector = sun.nio.ch.KQueueSelectorImpl@9a029e
> clientOperations = serverOperations = thread = Thread[TCPSelector,5,main]
> running = true
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> TCPAcceptor[0.0.0.0:2,036]
> main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering server
> operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> server operation REGISTER sun.nio.ch.ServerSocketChannelImpl[unbound]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
> sun.nio.ch.ServerSocketChannelImpl[unbound]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPAcceptor@5
> Acceptor.negotiator = null
> Acceptor.bufferProvider = BufferPool[4,096]
> Acceptor.protocolFactoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.serverProtocols[echo]=Factory[org.eclipse. net4j.serverProtocols,
> echo]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> Acceptor.protocolPostProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> Acceptor.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@5660d6
> Acceptor.lifecycleEventConverter =
> org.eclipse.internal.net4j.acceptor.Acceptor$1@ef83d3
> Acceptor.acceptedConnectors = selector = TCPSelector
> selectionKey = sun.nio.ch.SelectionKeyImpl@b40ec4
> startSynchronously = true
> synchronousStartTimeout = 4000
> startLatch = java.util.concurrent.CountDownLatch@faa550[Count = 0]
> serverSocketChannel = sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:2036]
> address = 0.0.0.0
> port = 2036
>
> [INFO] Accepting connections: TCPAcceptor[0.0.0.0:2,036]
> Press any key to shutdown
>
>
> ===================== Server Trace ======================
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ManagedContainer
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> {org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
> tcp],
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default],
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo],
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp],
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default],
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp],
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]}
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> HashMapRegistry@1
> Registry.autoCommit = true
> Registry.transaction = null
> map =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ManagedContainer@2
> factoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> postProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> elementRegistry = maxElementID = 0
> elementListener =
> org.eclipse.net4j.internal.util.container.ManagedContainer$1@bf3d87
>
> main [org.eclipse.internal.net4j.connector.Connector] Setting userID
> null for ClientTCPConnector[null:0]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> BufferPool[4,096]
> BufferPoolMonitor [org.eclipse.internal.net4j.buffer.BufferPool] Start
> monitoring
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> BufferPool@3
> BufferProvider.bufferCapacity = 4096
> BufferProvider.providedBuffers = 0
> BufferProvider.retainedBuffers = 0
> provider = BufferFactory[4,096]
> pooledBuffers = 0
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> TCPSelector
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPSelector@4
> selector = sun.nio.ch.KQueueSelectorImpl@722456
> clientOperations = serverOperations = thread = Thread[TCPSelector,5,main]
> running = true
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ClientTCPConnector[localhost:2,036]
> main [org.eclipse.internal.net4j.connector.Connector] Setting state
> CONNECTING (was disconnected) for ClientTCPConnector[localhost:2,036]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> Channel[Control]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> ChannelReceiveSerializer@5
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ChannelReceiveSerializer@5
> Worker.daemon = false
> Worker.activationTimeout = 2000
> Worker.deactivationTimeout = 2000
> Worker.activationLatch =
> java.util.concurrent.CountDownLatch@cebc9f[Count = 0]
> Worker.workerThread = Thread[ReceiveSerializer-1,5,main]
> QueueWorker.queue = QueueWorker.pollMillis = 100
>
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> ControlChannel@6
> Channel.channelID = 0
> Channel.channelMultiplexer = ClientTCPConnector[localhost:2,036]
> Channel.channelIndex = -1
> Channel.receiveExecutor = java.util.concurrent.ThreadPoolExecutor@1fc1a6
> Channel.receiveHandler = null
> Channel.receiveSerializer = ChannelReceiveSerializer@5
> Channel.sendQueue = registrations = SynchronizingCorrelator{}
>
> main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
> operation REGISTER java.nio.channels.SocketChannel[unconnected]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation REGISTER java.nio.channels.SocketChannel[unconnected]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Registering
> java.nio.channels.SocketChannel[unconnected]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Connecting
> java.nio.channels.SocketChannel[connection-pending
> remote=localhost/127.0.0.1:2036]
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering
> client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering
> client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.internal.net4j.connector.Connector] Setting
> state CONNECTED (was connecting) for ClientTCPConnector[localhost:2,036]
> TCPSelector [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> TCPClientConnector@7
> Connector.userID = null
> Connector.protocolFactoryRegistry =
> org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j. connectors,
> tcp]
>
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default]
>
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo]
>
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp]
>
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default]
>
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp]
>
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]
> Connector.protocolPostProcessors =
> org.eclipse.internal.net4j.Net4jTransportInjector@82764b
> org.eclipse.net4j.internal.tcp.TCPSelectorInjector@2452e8
> Connector.negotiator = null
> Connector.negotiationContext = null
> Connector.bufferProvider = BufferPool[4,096]
> Connector.receiveExecutor =
> java.util.concurrent.ThreadPoolExecutor@1fc1a6
> Connector.nextChannelID = 1
> Connector.channels = Connector.channelsLock =
> org.eclipse.net4j.util.concurrent.RWLock@15126e[Write locks = 0, Read
> locks = 0]
> Connector.connectorState = CONNECTED
> Connector.channelListener =
> org.eclipse.internal.net4j.connector.Connector$1@6d2380
> Connector.finishedConnecting =
> java.util.concurrent.CountDownLatch@35b1f3[Count = 1]
> Connector.finishedNegotiating =
> java.util.concurrent.CountDownLatch@35e6e3[Count = 1]
> TCPConnector.socketChannel = java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036]
> TCPConnector.selector = TCPSelector
> TCPConnector.selectionKey = sun.nio.ch.SelectionKeyImpl@a1c42f
> TCPConnector.writeQueue = TCPConnector.inputBuffer = null
> TCPConnector.controlChannel = Channel[Control]
> TCPConnector.host = localhost
> TCPConnector.port = 2036
>
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST CONNECT
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest (was connect)
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST READ
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest READ
> main [org.eclipse.internal.net4j.connector.Connector] Waiting for
> connection...
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] Activating
> SignalProtocol[echo]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle] DUMP
> EchoClientProtocol@8
> Protocol.channel = Channel[-32,768]
> Protocol.bufferProvider = BufferPool[4,096]
> Protocol.executorService = java.util.concurrent.ThreadPoolExecutor@1fc1a6
> Protocol.infraStructure = null
> SignalProtocol.streamWrapper = null
> SignalProtocol.signals = SignalProtocol.nextCorrelationID = 1
>
> main [org.eclipse.internal.net4j.connector.Connector] Opening channel
> 0 with protocol echo
> main [org.eclipse.net4j.internal.tcp.ControlChannel] Registering
> channel 0 with protocol SignalProtocol[echo]
> main [org.eclipse.internal.net4j.buffer.BufferFactory] Created Buffer@9
> main [org.eclipse.internal.net4j.buffer.BufferPool] Obtained Buffer@9
> main [org.eclipse.internal.net4j.channel.Channel] Handling buffer from
> client: Buffer@9 --> Channel[Control]
> main [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering client
> operation INTEREST WRITE java.nio.channels.SocketChannel[connected
> local=/127.0.0.1:53214 remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = true
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest READ|WRITE (was read)
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Writing
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036]
> TCPSelector [org.eclipse.internal.net4j.buffer.Buffer] Writing 13 bytes
> 02 00 00 00 01 00 00 00 04 65 63 68 6f TCPSelector
> [org.eclipse.internal.net4j.buffer.BufferPool] Retaining Buffer@9
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Ordering
> client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.TCPSelector] Executing
> client operation INTEREST WRITE
> java.nio.channels.SocketChannel[connected local=/127.0.0.1:53214
> remote=localhost/127.0.0.1:2036] = false
> TCPSelector [org.eclipse.net4j.internal.tcp.SelectorUtil] Setting
> interest READ (was read|write)
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating ManagedContainer
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating ClientTCPConnector[localhost:2,036]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating Channel[Control]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating ChannelReceiveSerializer@5
> main [org.eclipse.internal.net4j.connector.Connector] Setting state
> DISCONNECTED (was connected) for ClientTCPConnector[localhost:2,036]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating TCPSelector
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating BufferPool[4,096]
> main [org.eclipse.net4j.internal.util.lifecycle.Lifecycle]
> Deactivating
> {org.eclipse.net4j.connectors[tcp]=Factory[org.eclipse.net4j .connectors,
> tcp],
> org.eclipse.net4j.randomizers[default]=Factory[org.eclipse.n et4j.randomizers,
> default],
> org.eclipse.net4j.clientProtocols[echo]=Factory[org.eclipse. net4j.clientProtocols,
> echo],
> org.eclipse.net4j.selectors[tcp]=Factory[org.eclipse.net4j.s electors,
> tcp],
> org.eclipse.net4j.bufferProviders[default]=Factory[org.eclip se.net4j.bufferProviders,
> default],
> org.eclipse.net4j.acceptors[tcp]=Factory[org.eclipse.net4j.a cceptors,
> tcp],
> org.eclipse.net4j.executorServices[default]=Factory[org.ecli pse.net4j.executorServices,
> default]}
> Exception in thread "main" BufferPoolMonitor
> [org.eclipse.internal.net4j.buffer.BufferPool] Stop monitoring
> org.eclipse.net4j.util.concurrent.TimeoutRuntimeException:
> Registration timeout after 10000 milliseconds
> at
> org.eclipse.net4j.internal.tcp.ControlChannel.registerChanne l(ControlChannel.java:89)
>
> at
> org.eclipse.net4j.internal.tcp.TCPConnector.registerChannelW ithPeer(TCPConnector.java:269)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:401)
>
> at
> org.eclipse.internal.net4j.connector.Connector.openChannel(C onnector.java:388)
>
> at
> org.eclipse.net4j.examples.echo.client.EchoClient.main(EchoC lient.java:51)
>
>
>
>
>
>
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
| Re: [CDO] Client registration timeout exception [message #616301 is a reply to message #118265] |
Tue, 15 April 2008 05:39 |
| Eclipse User |
|
|
|
Originally posted by: ben.razzledazzle.gmail.com
Hi Eike,
A friend (who is much smarter than me) looked at this problem and has
discovered that on OS X the ordering of binding and registering of the
server socket makes a big difference. The binding should occur before the
registering on OSX.
He discovered this by using the code here:
http://www.exampledepot.com/egs/java.nio/NbServer.html
To test it, run the above NbServer code and then telnet into the socket
after the selector.select() is executed. If everything is working fine
then the telnet triggers the selector to wake and rest of the code is run.
When the binding occurs _before_ the registration everything works fine.
When the binding occurs _after_ the registration the selector.select()
never wakes up.
(This has been verified on two different machines)
So the Net4J, the problem occurs because the binding
(org.eclipse.net4j.internal.tcp.TCPAcceptor+handleRegistrati on) occurs
_after_ the registration
(org.eclipse.net4j.internal.tcp.TCPSelector+executeRegistrat ion).
This was confirmed when we did a quick hack in Net4J to change it so that
the binding occures _before_ the registration. After we did the
EchoServer worked correctly and so did the CDO server.
This is the hack:
In org.eclipse.net4j.internal.tcp.TCPSelector + executeRegistration was
changed so that the listener.handleRegistration is called twice:
- before the registration, so the binding can occur in the TCPAcceptor
- after the registration, so the selectionKey can be stored in the
TCPAcceptor
I also moved the trace so it is clear that the registration occurs after
the binding.
private void executeRegistration(final ServerSocketChannel channel,
final ITCPSelectorListener.Passive listener)
{
try
{
int interest = SelectionKey.OP_ACCEPT;
//*** NEW **//
listener.handleRegistration(null);
//************//
if (TRACER.isEnabled())
{
TRACER.trace("Registering " + channel); //$NON-NLS-1$
}
SelectionKey selectionKey = channel.register(selector, interest,
listener);
listener.handleRegistration(selectionKey);
}
catch (ClosedChannelException ex)
{
ex.printStackTrace();
OM.LOG.error(ex);
}
}
org.eclipse.net4j.internal.tcp.TCPAcceptor+ handleRegistration
- a check was added so that the selectionKey is set the second time the
method is called.
- a trace was added to show when the binding occured.
public void handleRegistration(SelectionKey selectionKey)
{
//*** NEW **//
if (this.selectionKey == null && selectionKey != null) {
this.selectionKey = selectionKey;
return;
}
//************//
try
{
InetSocketAddress addr = null;
if (address != null)
{
addr = new InetSocketAddress(InetAddress.getByName(address), port);
}
ServerSocket socket = serverSocketChannel.socket();
//*** NEW **//
if (TRACER.isEnabled())
{
TRACER.trace("Binding to server socket to address"); //$NON-NLS-1$
}
//************/
socket.bind(addr);
if (addr == null)
{
address = socket.getInetAddress().toString();
if (address.startsWith("/"))
{
address = address.substring(1);
}
int colon = address.indexOf(':');
if (colon != -1)
{
port = Integer.parseInt(address.substring(colon + 1));
address = address.substring(0, colon);
}
}
}
catch (Exception ex)
{
OM.LOG.error(ex);
deactivate();
}
finally
{
if (startLatch != null)
{
startLatch.countDown();
}
}
}
|
|
|
| Re: [CDO] Client registration timeout exception [message #616305 is a reply to message #118360] |
Tue, 15 April 2008 11:00 |
|
Hi Ben,
Great analysis! It would help me a lot if you could file a Bugzilla and
attach your changes as a patch against the latests HEAD of CVS. This way
you'll also be informed when I commit your patch ;-)
Cheers
/Eike
Ben C. wrote:
> Hi Eike,
> A friend (who is much smarter than me) looked at this problem and has
> discovered that on OS X the ordering of binding and registering of the
> server socket makes a big difference. The binding should occur before the
> registering on OSX.
> He discovered this by using the code here:
> http://www.exampledepot.com/egs/java.nio/NbServer.html
> To test it, run the above NbServer code and then telnet into the socket
> after the selector.select() is executed. If everything is working fine
> then the telnet triggers the selector to wake and rest of the code is run.
> When the binding occurs _before_ the registration everything works fine.
> When the binding occurs _after_ the registration the selector.select()
> never wakes up.
> (This has been verified on two different machines)
> So the Net4J, the problem occurs because the binding
> (org.eclipse.net4j.internal.tcp.TCPAcceptor+handleRegistrati on) occurs
> _after_ the registration
> (org.eclipse.net4j.internal.tcp.TCPSelector+executeRegistrat ion).
> This was confirmed when we did a quick hack in Net4J to change it so that
> the binding occures _before_ the registration. After we did the
> EchoServer worked correctly and so did the CDO server.
> This is the hack:
> In org.eclipse.net4j.internal.tcp.TCPSelector + executeRegistration was
> changed so that the listener.handleRegistration is called twice:
> - before the registration, so the binding can occur in the TCPAcceptor
> - after the registration, so the selectionKey can be stored in the
> TCPAcceptor
> I also moved the trace so it is clear that the registration occurs after
> the binding.
> private void executeRegistration(final ServerSocketChannel channel,
> final ITCPSelectorListener.Passive listener)
> {
> try
> {
> int interest = SelectionKey.OP_ACCEPT;
> //*** NEW **//
> listener.handleRegistration(null);
> //************//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Registering " + channel); //$NON-NLS-1$
> }
> SelectionKey selectionKey = channel.register(selector, interest,
> listener);
> listener.handleRegistration(selectionKey);
> }
> catch (ClosedChannelException ex)
> {
> ex.printStackTrace();
> OM.LOG.error(ex);
> }
> }
> org.eclipse.net4j.internal.tcp.TCPAcceptor+ handleRegistration
> - a check was added so that the selectionKey is set the second time the
> method is called.
> - a trace was added to show when the binding occured.
> public void handleRegistration(SelectionKey selectionKey)
> {
> //*** NEW **//
> if (this.selectionKey == null && selectionKey != null) {
> this.selectionKey = selectionKey;
> return;
> }
> //************//
> try
> {
> InetSocketAddress addr = null;
> if (address != null)
> {
> addr = new InetSocketAddress(InetAddress.getByName(address), port);
> }
> ServerSocket socket = serverSocketChannel.socket();
> //*** NEW **//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Binding to server socket to address"); //$NON-NLS-1$
> }
> //************/
> socket.bind(addr);
> if (addr == null)
> {
> address = socket.getInetAddress().toString();
> if (address.startsWith("/"))
> {
> address = address.substring(1);
> }
> int colon = address.indexOf(':');
> if (colon != -1)
> {
> port = Integer.parseInt(address.substring(colon + 1));
> address = address.substring(0, colon);
> }
> }
> }
> catch (Exception ex)
> {
> OM.LOG.error(ex);
> deactivate();
> }
> finally
> {
> if (startLatch != null)
> {
> startLatch.countDown();
> }
> }
> }
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
| Re: [CDO] Client registration timeout exception [message #617858 is a reply to message #118360] |
Sun, 20 April 2008 08:13 |
|
Hi Ben,
I've refactored the registration protocol between TCPSelector and
TCPAcceptor/TCPConnector:
https://bugs.eclipse.org/bugs/show_bug.cgi?id=227880
Since I can't test it on Mac OS can you please confirm that the problem
is fixed?
Cheers
/Eike
Ben C. schrieb:
> Hi Eike,
> A friend (who is much smarter than me) looked at this problem and has
> discovered that on OS X the ordering of binding and registering of the
> server socket makes a big difference. The binding should occur before
> the registering on OSX.
>
> He discovered this by using the code here:
> http://www.exampledepot.com/egs/java.nio/NbServer.html
>
> To test it, run the above NbServer code and then telnet into the
> socket after the selector.select() is executed. If everything is
> working fine then the telnet triggers the selector to wake and rest of
> the code is run.
>
> When the binding occurs _before_ the registration everything works fine.
> When the binding occurs _after_ the registration the selector.select()
> never wakes up. (This has been verified on two different machines)
>
> So the Net4J, the problem occurs because the binding
> (org.eclipse.net4j.internal.tcp.TCPAcceptor+handleRegistrati on) occurs
> _after_ the registration
> (org.eclipse.net4j.internal.tcp.TCPSelector+executeRegistrat ion).
>
> This was confirmed when we did a quick hack in Net4J to change it so
> that the binding occures _before_ the registration. After we did the
> EchoServer worked correctly and so did the CDO server.
>
> This is the hack:
>
> In org.eclipse.net4j.internal.tcp.TCPSelector + executeRegistration
> was changed so that the listener.handleRegistration is called twice:
> - before the registration, so the binding can occur in the
> TCPAcceptor
> - after the registration, so the selectionKey can be stored in the
> TCPAcceptor
>
> I also moved the trace so it is clear that the registration occurs
> after the binding.
>
> private void executeRegistration(final ServerSocketChannel channel,
> final ITCPSelectorListener.Passive listener)
> {
> try
> {
> int interest = SelectionKey.OP_ACCEPT;
> //*** NEW **//
> listener.handleRegistration(null);
> //************//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Registering " + channel); //$NON-NLS-1$
> }
> SelectionKey selectionKey = channel.register(selector, interest,
> listener);
> listener.handleRegistration(selectionKey);
> }
> catch (ClosedChannelException ex)
> {
> ex.printStackTrace();
> OM.LOG.error(ex);
> }
> }
>
>
>
>
> org.eclipse.net4j.internal.tcp.TCPAcceptor+ handleRegistration
>
> - a check was added so that the selectionKey is set the second time
> the method is called. - a trace was added to show when the binding
> occured.
>
> public void handleRegistration(SelectionKey selectionKey)
> {
> //*** NEW **//
> if (this.selectionKey == null && selectionKey != null) {
> this.selectionKey = selectionKey;
> return; }
> //************//
> try
> {
> InetSocketAddress addr = null;
> if (address != null)
> {
> addr = new InetSocketAddress(InetAddress.getByName(address),
> port);
> }
>
> ServerSocket socket = serverSocketChannel.socket();
> //*** NEW **//
> if (TRACER.isEnabled())
> {
> TRACER.trace("Binding to server socket to address"); //$NON-NLS-1$
> }
> //************/
> socket.bind(addr);
>
> if (addr == null)
> {
> address = socket.getInetAddress().toString();
> if (address.startsWith("/"))
> {
> address = address.substring(1);
> }
>
> int colon = address.indexOf(':');
> if (colon != -1)
> {
> port = Integer.parseInt(address.substring(colon + 1));
> address = address.substring(0, colon);
> }
> }
> }
> catch (Exception ex)
> {
> OM.LOG.error(ex);
> deactivate();
> }
> finally
> {
> if (startLatch != null)
> {
> startLatch.countDown();
> }
> }
> }
>
>
>
>
>
Cheers
/Eike
----
http://www.esc-net.de
http://thegordian.blogspot.com
http://twitter.com/eikestepper
|
|
|
Goto Forum:
Current Time: Fri Apr 19 22:45:33 GMT 2024
Powered by FUDForum. Page generated in 0.05218 seconds |
] 
Search
Help
Register
Login
Home
