4 seconds to load 20 rows

[sieroka]

We're using JBoss 3.0.3 with SqlServer2000 and Oracle8i. We have a table that has 20 records and about 10 columns, all varchar2 or number. It takes about 4 seconds to load these records. We have a remote session looking up a local entity, which calls findAll(). Every call to the same session bean still takes 4 seconds.
Any ideas?

[joelvogt]

I'm a bit confused about your setup, why sqlserver and oracle?
A call like that shouldn't take 4 seconds. Possibly it is creating a new database connection each time? With your driver is it possibly to put a trace on the jdbc calls? Have a look at this and see what is going on.

[sieroka]

We're not actaully using them at the same time, but want our application to support both.

I changed the log4j.xml to debug, and I see lines like this executed eight times. After this the number of "(EVENT_TYPE=?) OR " reduces by one, and 8 more, and again and again, until it finally returns the records:

2002-11-06 08:47:56,433 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCEJBQLQuery.EventType.findAll] Executing SQL: SELECT t0_o.EVENT_TYPE FROM PS_EVENT_TYPE t0_o
2002-11-06 08:47:56,441 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType] Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)

[sieroka]

We don't actually use both Oracle and SqlServer at the same time, we just want our application to support both.

When I turn on debug, I get the following output. The number of "OR (EVENT_TYPE=?) " seems to start out as the same number of rows in the database. Each of these lines is repeated 8 times, and then the number of "OR (EVENT_TYPE=?) " reduces by one, and the pattern continues, until the is only one "OR (EVENT_TYPE=?) " and then the data is returned.

We're using LocalTx? Is this ok to run NotSupported methods? Should we be using XaTx, or NoTx? If I lookup a connection to LocalTx datasource manually and run a select SqlQuery, will that be under a transaction?

2002-11-06 08:48:09,584 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType] Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)

[sieroka]

We're getting a Collection from the findAll() method and then getting an Iterator to fo through each remote obejct and create our own objects from them. It seems that as we go through the iterator the sql calls continnue. The reducing number of "OR (EVENT_TYPE=?)" seems to correspond with us going through the Iterator. I know it sounds strange, but I have no other ideas a this point...

[sieroka]

Here's a code snippet and the result in the logs. I changed from Iterator to [] just to see if it would make a difference, but it doesn't:

CODE:
Object[] lObjectArray = pCollection.toArray();
try
{
int len = lObjectArray.length;
for ( int i = 0 ; i < len ; i ++ ) {
sLog.debug( "createEventTypeSDOS(AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA) called..." );
lEventTypeSdo = getData((EventType)lObjectArray);
sLog.debug( "createEventTypeSDOS(BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB) called..." );
lEventTypeArrayList.add(lEventTypeSdo);
sLog.debug( "createEventTypeSDOS(CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC) called..." );
}
}
catch (Exception re)

public static EventTypeSdo getData(EventType pEventType)
throws Exception
{
EventTypeSdo lEventTypeSdo = null;
String lErrStr = null;
try
{
lEventTypeSdo = new EventTypeSdo(
pEventType.getEventType(),
pEventType.getDescription(),
pEventType.getSeverity(),
pEventType.getCategory(),
pEventType.getNeedsResolution(),
pEventType.getOutputContentTemplate(),
pEventType.getCreateTime(),
pEventType.getLastUpdatedTime()
);
}
catch (Exception e)


LOGS:
2002-11-06 14:12:16.151 EST - DEBUG - com.platespin.oss.rbc.commands.event.EventTypeActionCRUDBean[RMI TCP Connection(11)-10.1.1.185] - createEventTypeSDOS(AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA) called...
2002-11-06 14:12:16.156 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.339 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.379 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.479 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.529 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.577 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.604 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.670 EST - DEBUG - org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.EventType[RMI TCP Connection(11)-10.1.1.185] - Executing SQL: SELECT EVENT_TYPE,DESCRIPTION, SEVERITY, CATEGORY, NEEDS_RESOLUTION, OUTPUT_CONTENT_TEMPLATE, CREATE_TIME, LAST_UPDATED_TIME FROM PS_EVENT_TYPE WHERE (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?) OR (EVENT_TYPE=?)
2002-11-06 14:12:16.689 EST - DEBUG - com.platespin.oss.rbc.commands.event.EventTypeActionCRUDBean[RMI TCP Connection(11)-10.1.1.185] - createEventTypeSDOS(BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB) called...
2002-11-06 14:12:16.689 EST - DEBUG - com.platespin.oss.rbc.commands.event.EventTypeActionCRUDBean[RMI TCP Connection(11)-10.1.1.185] - createEventTypeSDOS(CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC) called...
2002-11-06 14:12:16.689 EST - DEBUG - com.platespin.oss.rbc.commands.event.EventTypeActionCRUDBean[RMI TCP Connection(11)-10.1.1.185] - createEventTypeSDOS(AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA) called...

[sieroka]

I looks like every call to a local entity getter results in another sql statement call in the container.

[adrian.brock]

By default it will "read-ahead" to avoid
the multiple sql statements. But this only works
within the same transaction.

Change it to use "Required".
You will only get the first two sql statements.

Regards,
Adrian