RQMI server start error
I am trying to get the RQMI server running on my machine, and am getting an error when trying to start it.
I am running JTS 3.0.1.1 and DOORS 9.3.0.4 on a single Windows 7 Pro machine. The RQMI startup gets through the login to the QM server, then throws an exception but seems to continue to run (hung, maybe?) DOORS tells me I have a problem with my RQM Interface server when I try to export the view to RQM.
I set logging to level 2 and here is what it dumps out (exception is at the bottom):
Logging level: 2
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise RMI_HOST: rg39a
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise RMI_PORT: 7764
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise RMI_PORT2: 7765
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise POOL_SIZE: 20
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise IPC_PORT: 8768
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: GET _registryManager
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Attempting to get an existing registry ...
creating SSL ServerSocket on port 7764
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Existing registry retieved
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: RQMI Server v1.03.0004 starting...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: RMI_PORT: 7764
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Database connection string:jdbc:derby:../../rqmdrsDB;create=false;user=admin;password=<encryp>
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: derby.locks.deadlockTimeout=15
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: derby.locks.waitTimeout=60
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: The connection is live
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: DBManager.executeGet: BeforeQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: BeforePrepareStatement(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: AfterPrepareStatement(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: BeforeQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: AfterQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: DBManager.executeGet: AfterQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: FieldCount = 5
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: DBManager.executeGet: RowCount = 1
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: Synchronisation started for: 36677@rg39a
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: URL Synchronisation started for: 36677@rg39a
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: Initialising server ...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log sync
INFO: Sync Interval = 1440
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log sync
INFO: Sync Interval is: 1440 minutes.
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log sync
INFO: URL Sync Interval = 1440
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: creating ServerSocket on port 7765
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: get(ResourceType: ALL_PROJECT_AREAS)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: the worker has been created
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Getting from ... /qm/secure/service/com.ibm.rqm.integration.service.IIntegrationService/proje
ts?abbreviate=false
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: client reference
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Start new thread for submitting SSL to RQM
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Security provider
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: client Object created
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: requesting authrequired ...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: requesting initialization data ...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Logging into RQM ...
Nov 4, 2011 9:46:32 AM uk.co.stpsoft.util.Log server
INFO: responseCode ...200
Nov 4, 2011 9:46:32 AM uk.co.stpsoft.util.Log server
INFO: Login request status 200
Exception in thread "main" java.lang.StringIndexOutOfBoundsException
at java.lang.String.substring(String.java:1088)
at uk.co.stpsoft.exportserver.RemoteRQMWorker.get(Unknown Source)
at uk.co.stpsoft.exportserver.RQMRMI.initialiseNextTestPlanId(Unknown Source)
at uk.co.stpsoft.exportserver.RQMRMI.main(Unknown Source)
Nov 4, 2011 9:47:31 AM uk.co.stpsoft.util.Log sync
INFO: URL Sync Interval = 1440
Nov 4, 2011 9:48:31 AM uk.co.stpsoft.util.Log sync
INFO: URL Sync Interval = 1440
I have looked through all the startup and properties files I can think of, and set the rqm root to QM via the DOORS admin -c command.
What else should I check?
I am running JTS 3.0.1.1 and DOORS 9.3.0.4 on a single Windows 7 Pro machine. The RQMI startup gets through the login to the QM server, then throws an exception but seems to continue to run (hung, maybe?) DOORS tells me I have a problem with my RQM Interface server when I try to export the view to RQM.
I set logging to level 2 and here is what it dumps out (exception is at the bottom):
Logging level: 2
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise RMI_HOST: rg39a
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise RMI_PORT: 7764
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise RMI_PORT2: 7765
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise POOL_SIZE: 20
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Initialise IPC_PORT: 8768
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: GET _registryManager
Nov 4, 2011 9:46:30 AM uk.co.stpsoft.util.Log server
INFO: Attempting to get an existing registry ...
creating SSL ServerSocket on port 7764
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Existing registry retieved
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: RQMI Server v1.03.0004 starting...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: RMI_PORT: 7764
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Database connection string:jdbc:derby:../../rqmdrsDB;create=false;user=admin;password=<encryp>
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: derby.locks.deadlockTimeout=15
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: derby.locks.waitTimeout=60
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: The connection is live
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: DBManager.executeGet: BeforeQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: BeforePrepareStatement(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: AfterPrepareStatement(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: BeforeQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Procedure: AfterQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: DBManager.executeGet: AfterQuery(SELECT * FROM Database)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: FieldCount = 5
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: DBManager.executeGet: RowCount = 1
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: Synchronisation started for: 36677@rg39a
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: URL Synchronisation started for: 36677@rg39a
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log app
INFO: Initialising server ...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log sync
INFO: Sync Interval = 1440
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log sync
INFO: Sync Interval is: 1440 minutes.
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log sync
INFO: URL Sync Interval = 1440
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: creating ServerSocket on port 7765
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: get(ResourceType: ALL_PROJECT_AREAS)
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: the worker has been created
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Getting from ... /qm/secure/service/com.ibm.rqm.integration.service.IIntegrationService/proje
ts?abbreviate=false
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: client reference
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Start new thread for submitting SSL to RQM
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Security provider
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: client Object created
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: requesting authrequired ...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: requesting initialization data ...
Nov 4, 2011 9:46:31 AM uk.co.stpsoft.util.Log server
INFO: Logging into RQM ...
Nov 4, 2011 9:46:32 AM uk.co.stpsoft.util.Log server
INFO: responseCode ...200
Nov 4, 2011 9:46:32 AM uk.co.stpsoft.util.Log server
INFO: Login request status 200
at java.lang.String.substring(String.java:1088)
at uk.co.stpsoft.exportserver.RemoteRQMWorker.get(Unknown Source)
at uk.co.stpsoft.exportserver.RQMRMI.initialiseNextTestPlanId(Unknown Source)
at uk.co.stpsoft.exportserver.RQMRMI.main(Unknown Source)
Nov 4, 2011 9:47:31 AM uk.co.stpsoft.util.Log sync
INFO: URL Sync Interval = 1440
Nov 4, 2011 9:48:31 AM uk.co.stpsoft.util.Log sync
INFO: URL Sync Interval = 1440
I have looked through all the startup and properties files I can think of, and set the rqm root to QM via the DOORS admin -c command.
What else should I check?