Are you timing the lookup of just this request? Or the end-to-end response? Also is the CPU spinning?
Hi Kurt, thanks for the quick response.
Yes, I am only timing the findEPR invocation use the folowing code.
long t0 = System.currentTimeMillis();
EPR requestEPR = (EPR)registry.findEPR(category, service);
System.out.println("TIME: " + (System.currentTimeMillis()-t0));
The CPU use does not rise wile permorfimg the task.
Now I'm really curious what it's doing.. No errors huh? Are you configured to do a "LocalTransport" from Scout to jUDDI? (Not RMI). It should be much, much faster (0.2 s). Note that for MP1 we extended our lifecycle support and lookups now happen far less frequent.
I'm not getting errors and it works fine. It does the job but takes too long to lookup the ESB services.
I'm using LocalTransport in the jbossesb-properties.xml. In fact I have not changed this file since the installation.
The registry section of the file looks like this.
<properties name="registry"> <property name="org.jboss.soa.esb.registry.queryManagerURI" value="org.apache.juddi.registry.local.InquiryService#inquire"/> <property name="org.jboss.soa.esb.registry.lifeCycleManagerURI" value="org.apache.juddi.registry.local.PublishService#publish"/> <property name="org.jboss.soa.esb.registry.implementationClass" value="org.jboss.internal.soa.esb.services.registry.JAXRRegistryImpl"/> <property name="org.jboss.soa.esb.registry.factoryClass" value="org.apache.ws.scout.registry.ConnectionFactoryImpl"/> <property name="org.jboss.soa.esb.registry.user" value="jbossesb"/> <property name="org.jboss.soa.esb.registry.password" value="password"/> <!-- the following parameter is scout specific to set the type of communication between scout and the UDDI (embedded, rmi, soap) --> <property name="org.jboss.soa.esb.scout.proxy.transportClass" value="org.apache.ws.scout.transport.LocalTransport"/> </properties>
I'm using the 4.0 GA version of th ESB.
Can you you turn on debug logging for scout and juddi?
I could not find the configuration to turn on debugging messages for scout or juddi. I'd be grateful if you could tell me were to do it.
Anyways I monitored the mysql juddi database using MySQLAdministrator and found that while the request was beeing processed the amount of queries was huge. The screenshot is here: http://img410.imageshack.us/img410/9748/mysqlloadtj0.png .
The number of services that need to be looked up is 7 and it took 140 seconds to satisfy the request but the database performed about 150 querys per second during that time (arround 21000 queries).
I am really puzzled by this. Has something like this ever happened to anyone? I may be ignoring something important.
For the logging you should modify the conf/log4j.xml file, turning on DEBUG for org.apache.juddi and org.apache.scout.
I'm also puzzled by the amount of queries that you are seeing. Maybe you can dig into that a little more. Can you obtain a log of the queries? And get the number of rows in each table in the juddi schema?
The debugging log for juddi or scout does not help much but I am capturing the sql queries that are being executed by the mysql server. The amount of queries being executed is very high. I assume that this is done in order to be able to work on many different databse engines. I can't post the log here for space reasons but I could send it by email if necessary.
I am getting lookup times now of between half a second and three seconds using a local mysql database but I still thik that he times are high.
The amount of records on each table is as follows.
ADDRESS 1 ADDRESS_LINE 6 AUTH_TOKEN 203 BINDING_CATEGORY 0 BINDING_DESCR 5 BINDING_TEMPLATE 125 BUSINESS_CATEGORY 0 BUSINESS_DESCR 1 BUSINESS_ENTITY 1 BUSINESS_IDENTIFIER 0 BUSINESS_NAME 1 BUSINESS_SERVICE 26 CONTACT 1 CONTACT_DESCR 0 DISCOVERY_URL 1 EMAIL 1 INSTANCE_DETAILS_DESCR 0 INSTANCE_DETAILS_DOC_DESCR 0 PHONE 1 PUBLISHER 1 PUBLISHER_ASSERTION 0 SERVICE_CATEGORY 0 SERVICE_DESCR 22 SERVICE_NAME 26 TMODEL 21 TMODEL_CATEGORY 33 TMODEL_DESCR 21 TMODEL_DOC_DESCR 21 TMODEL_IDENTIFIER 0 TMODEL_INSTANCE_INFO 0 TMODEL_INSTANCE_INFO_DESCR 0
I noticed that the first sql query that's executed in order to find the service is the following.
SELECT S.SERVICE_KEY,S.LAST_UPDATE,N.NAME FROM BUSINESS_SERVICE S,SERVICE_NAME N WHERE N.SERVICE_KEY = S.SERVICE_KEY AND ((UPPER(NAME) LIKE 'SRVLOGUEOCATEG%') OR (UPPER(NAME) LIKE 'LOGUEO%')) ORDER BY N.NAME DESC,S.LAST_UPDATE DESC
Where SRVLOGUEOCATEG is the category and LOGUEO is the service name.
Why the LIKE statement with the % wildcard?
Thanks for all your help,
Can you email me the files? Or open a jira and attach the files? I'd like to be able to reproduce it.