Hi all,

In my "CompanyBean" (CMP) I have field of type String named "symbol" which is primary 
key.
I also have finder "findAll" with EJB-QL query "SELECT OBJECT(c) FROM Company c".

In "CompanyManagerBean" (SLSB) there is method "findAll" which contains code :


[ -=- snip -=- ]


        log.debug(" +-+-+-+-+- JUST BEFORE getCompanyLocalHome() -+-+-+-+-+");
        CompanyLocalHome companyLocalHome = IntaktHelper.getCompanyLocalHome();

        log.debug(" +-+-+-+-+- JUST BEFORE findAll() -+-+-+-+-+");
        Iterator iterator = companyLocalHome.findAll().iterator();
        log.debug(" +-+-+-+-+- JUST AFTER  findAll() -+-+-+-+-+");

ArrayList symbols = new ArrayList();

        while(iterator.hasNext()) {
                symbols.add((String)((CompanyLocal)iterator.next()).getSymbol());
        }

[ -=- snip -=- ]



There are 5000 companies in the database and this takes about over 15 seconds.
This is what I have in JBoss Log:


[ -=- snip -=- ] 2003-11-13 14:08:36,552 DEBUG [laser.ejb.intakt.IntaktBean ] (Thread-49:getCompaniesList) called 2003-11-13 14:08:36,552 DEBUG [laser.ejb.intakt.IntaktBean ] (Thread-49:getCompaniesList) ticketId :d52d83850a00016c0001d48c43e7176f 2003-11-13 14:08:36,552 DEBUG [laser.ejb.intakt.CompanyManagerBean ] (Thread-49:getCompaniesList findCompanies) called [ -=- snip -=- ] 2003-11-13 14:08:36,581 DEBUG [laser.ejb.intakt.CompanyManagerBean ] (Thread-49:getCompaniesList findCompanies) +-+-+-+-+- JUST BEFORE getCompanyLocalHome() -+-+-+-+-+ 2003-11-13 14:08:36,581 DEBUG [laser.ejb.intakt.CompanyManagerBean ] (Thread-49:getCompaniesList findCompanies) +-+-+-+-+- JUST BEFORE findAll() -+-+-+-+-+ 2003-11-13 14:08:36,582 DEBUG [laser.ejb.intakt.CompanyBean ] (Thread-49:getCompaniesList findCompanies setEntityContext) called 2003-11-13 14:08:36,582 DEBUG [laser.ejb.pacs.TicketBean ] (Thread-49:getCompaniesList findCompanies) *** stored! 2003-11-13 14:08:36,582 DEBUG [cmp.jdbc.JDBCStoreEntityCommand.Ticket ] (Thread-49:getCompaniesList findCompanies) Executing SQL: UPDATE Ticket SET expires=? WHERE id=? 2003-11-13 14:08:36,584 DEBUG [cmp.jdbc.JDBCStoreEntityCommand.Ticket ] (Thread-49:getCompaniesList findCompanies) Rows affected = 1 *** 2003-11-13 14:08:36,585 DEBUG [jdbc.JDBCEJBQLQuery.Company.findAll ] (Thread-49:getCompaniesList findCompanies) Executing SQL: SELECT t0_c.symbol FROM Company t0_c *** 2003-11-13 14:08:48,343 DEBUG [laser.ejb.intakt.CompanyManagerBean ] (Thread-49:getCompaniesList findCompanies) +-+-+-+-+- JUST AFTER findAll() -+-+-+-+-+ 2003-11-13 14:08:50,630 DEBUG [laser.ejb.intakt.CompanyManagerBean ] (Thread-49:getCompaniesList findCompanies) end 2003-11-13 14:08:50,631 DEBUG [laser.ejb.intakt.IntaktBean ] (Thread-49:getCompaniesList) end 2003-11-13 14:08:50,631 DEBUG [laser.ejb.intakt.CompanyBean ] (Thread-49:ejbStore) called 2003-11-13 14:08:50,631 DEBUG [laser.ejb.intakt.CompanyBean ] (Thread-49:ejbStore) called 2003-11-13 14:08:50,631 DEBUG [laser.ejb.intakt.CompanyBean ] (Thread-49:ejbStore) called 2003-11-13 14:08:50,631 DEBUG [laser.ejb.intakt.CompanyBean ] (Thread-49:ejbStore) called 2003-11-13 14:08:50,631 DEBUG [laser.ejb.intakt.CompanyBean ] (Thread-49:ejbStore) called ..... [laser.ejb.intakt.CompanyBean ] (Thread-49:ejbStore) CALLED 4995 more times .....

According to the logs "findAll" method takes little less then 12 seconds.
In the beginning I thought that there was new query to get the symbol from the 
database.
But here is what mySQL log shows:

        [ -=- snip -=- ]
        031113 14:08:36       9 Query       SET autocommit=0
                              9 Query       SELECT t0_c.symbol FROM Company t0_c
        031113 14:08:52       9 Query       commit
                              9 Query       SET autocommit=1
        [ -=- snip -=- ]


Now changing my code from :


        symbols.add((String)((CompanyLocal)iterator.next()).getSymbol());
to:
        symbols.add((String)((CompanyLocal)iterator.next()).getPrimaryKey());

results is much better performance:

            2003-11-13 14:27:16,098 DEBUG [laser.ejb.intakt.CompanyManagerBean     ] 
(Thread-46:getCompaniesList findCompanies) called
        [ -=- snip -=- ]
            2003-11-13 14:27:16,112 DEBUG [laser.ejb.intakt.CompanyManagerBean     ] 
(Thread-46:getCompaniesList findCompanies)  +-+-+-+-+- JUST BEFORE 
getCompanyLocalHome() -+-+-+-+-+
            2003-11-13 14:27:16,112 DEBUG [laser.ejb.intakt.CompanyManagerBean     ] 
(Thread-46:getCompaniesList findCompanies)  +-+-+-+-+- JUST BEFORE findAll() -+-+-+-+-+
            2003-11-13 14:27:16,112 DEBUG [laser.ejb.intakt.CompanyBean            ] 
(Thread-46:getCompaniesList findCompanies setEntityContext) called
            2003-11-13 14:27:16,112 DEBUG [laser.ejb.pacs.TicketBean               ] 
(Thread-46:getCompaniesList findCompanies)  *** stored!
            2003-11-13 14:27:16,113 DEBUG [cmp.jdbc.JDBCStoreEntityCommand.Ticket  ] 
(Thread-46:getCompaniesList findCompanies) Executing SQL: UPDATE Ticket SET expires=? 
WHERE id=?
            2003-11-13 14:27:16,114 DEBUG [cmp.jdbc.JDBCStoreEntityCommand.Ticket  ] 
(Thread-46:getCompaniesList findCompanies) Rows affected = 1
        *** 2003-11-13 14:27:16,115 DEBUG [jdbc.JDBCEJBQLQuery.Company.findAll     ] 
(Thread-46:getCompaniesList findCompanies) Executing SQL: SELECT t0_c.symbol FROM 
Company t0_c
        *** 2003-11-13 14:27:18,564 DEBUG [laser.ejb.intakt.CompanyManagerBean     ] 
(Thread-46:getCompaniesList findCompanies)  +-+-+-+-+- JUST AFTER  findAll() -+-+-+-+-+
            2003-11-13 14:27:18,564 DEBUG [laser.ejb.intakt.CompanyManagerBean     ] 
(Thread-46:getCompaniesList findCompanies)  iterate and  -- getPrimaryKey() -- and 
create VO!
            2003-11-13 14:27:18,576 DEBUG [laser.ejb.intakt.CompanyManagerBean     ] 
(Thread-46:getCompaniesList findCompanies) end
            2003-11-13 14:27:18,577 DEBUG [laser.ejb.intakt.IntaktBean             ] 
(Thread-46:getCompaniesList) end
        [laser.ejb.intakt.CompanyBean            ] (Thread-49:ejbStore) IS NOT CALLED 
AT ALL

As the log shows "jdbc.JDBCEJBQLQuery.Company.findAll" method takes now little over 2 
seconds.
But it still loads the same data from the database:

        [ -=- snip -=- ]
        031113 14:27:16      13 Query       SET autocommit=0
                             13 Query       SELECT t0_c.symbol FROM Company t0_c
        031113 14:27:18      13 Query       commit
                             13 Query       SET autocommit=1
        [ -=- snip -=- ]



My configuration is:  JBoss 3.2.1  |  Sun J2SDK 1.4.1_02-b06  |  Linux 2.4.22
I have set <commit-option>A</commit-option>.

I'm curious why it takes so long for doing 5000 times "getSymbol()" when there are no 
additional DB requests made?
Is this because of calling "ejbStore()"?
In another posting someone explained that "ejbStore()" is always called even if no 
synchronization is made
because the specs say so. But is it possible that calling 5000 times a method that 
basically does nothing,
causes such a performance loss?



Regards,
Milen Dyankov




------------------------------------------------------- This SF.Net email sponsored by: ApacheCon 2003, 16-19 November in Las Vegas. Learn firsthand the latest developments in Apache, PHP, Perl, XML, Java, MySQL, WebDAV, and more! http://www.apachecon.com/ _______________________________________________ JBoss-user mailing list [EMAIL PROTECTED] https://lists.sourceforge.net/lists/listinfo/jboss-user

Reply via email to