9 Replies Latest reply on Feb 18, 2003 4:39 PM by darryl_staflund

    CMR 1-Many Performance Woes

    darryl_staflund

      Hi all,

      I am running JBoss 3.0.4/Tomcat on Windows XP with a back-end PostgreSQL 7.2 database. I have coded a number of EJB 2.0 entity beans that stand in a one to many unidirectional relationship with each other. When I try to insert or delete entries using CMP 2.0, performance is awful. I have set up the controller methods to have a transaction requirement of 'RequiresNew' and the supporting methods as having a transaction requirement of 'Supported' or 'Required'.

      When insertions or deletions occur, though, beans are continually read and stored throughout the transaction and this is slowing things down imensely. Can someone tell me why this is happening? To give an idea of the lifecycle methods that are being performed, I provide the following clip. Comments and tips are appreciated.

      The following code is a snippet of the output I get when inserting approximately 1000 records into the database. It takes 1-2 minutes to perform.

      Sincerely,
      Darryl


      01:58:56,230 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:56,561 INFO [STDOUT] [SecurityActionEJB] Loaded.
      01:58:56,611 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:56,611 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:56,621 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:56,711 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.
      01:58:56,791 INFO [STDOUT] [SecurityActionEJB] Stored.
      01:58:56,791 INFO [STDOUT] [SecurityRoleEJB] Stored.
      01:58:56,831 INFO [STDOUT] [SecurityActionAssignmentEJB] Entity context has been set.
      01:58:56,831 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:56,971 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:56,971 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:56,981 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:56,981 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.
      01:58:57,021 INFO [STDOUT] [SecurityActionEJB] Stored.
      01:58:57,021 INFO [STDOUT] [SecurityRoleEJB] Stored.
      01:58:57,061 INFO [STDOUT] [SecurityActionAssignmentEJB] Entity context has been set.
      01:58:57,071 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:57,211 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:57,211 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:57,221 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:57,221 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.
      01:58:57,262 INFO [STDOUT] [SecurityActionEJB] Stored.
      01:58:57,262 INFO [STDOUT] [SecurityRoleEJB] Stored.
      01:58:57,312 INFO [STDOUT] [SecurityActionAssignmentEJB] Entity context has been set.
      01:58:57,312 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:57,402 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:57,402 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:57,402 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:57,402 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.
      01:58:57,452 INFO [STDOUT] [SecurityActionEJB] Stored.
      01:58:57,452 INFO [STDOUT] [SecurityRoleEJB] Stored.
      01:58:57,492 INFO [STDOUT] [SecurityActionAssignmentEJB] Entity context has been set.
      01:58:57,492 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:57,652 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:57,662 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:57,662 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:57,662 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.
      01:58:57,712 INFO [STDOUT] [SecurityActionEJB] Stored.
      01:58:57,722 INFO [STDOUT] [SecurityRoleEJB] Stored.
      01:58:57,752 INFO [STDOUT] [SecurityActionAssignmentEJB] Entity context has been set.
      01:58:57,762 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:57,842 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:57,852 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:57,852 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:57,852 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.
      01:58:57,902 INFO [STDOUT] [SecurityActionEJB] Stored.
      01:58:57,902 INFO [STDOUT] [SecurityRoleEJB] Stored.
      01:58:57,943 INFO [STDOUT] [SecurityActionAssignmentEJB] Entity context has been set.
      01:58:57,953 INFO [STDOUT] [SecurityActionAssignmentEJB] Created.
      01:58:58,143 INFO [STDOUT] [SecurityRoleEJB] Loaded.
      01:58:58,143 INFO [STDOUT] [SecurityActionAssignmentEJB] Post-created.
      01:58:58,153 INFO [STDOUT] [SecurityRoleEJB] Entity context has been set.
      01:58:58,153 INFO [STDOUT] [SecurityActionAssignmentEJB] Stored.

      etc...

        • 1. Re: CMR 1-Many Performance Woes
          lamarguy

          I had the exact same problem. after reading many of the related posts on the problem, it becomes readily clear that beans employing CMR are unusable due to laudable performance problems.

          if you create a couple of test cases you will quickly see that the runtime complexity is on the order of 2^n which is completely unusable in the real world.

          I've always liked and promoted jboss, but this is a sad state of affairs. I ended up converting my CMP beans to BMP after exhaustive attempts at achieving decent performance proved unsuccessful.

          • 2. Re: CMR 1-Many Performance Woes
            darryl_staflund

            Awww, so does that mean there's no way to address CMR performance problems without switching to CMP or DAOs or stored procs or ...? That's sad. I was hoping there's be some sort of CMP performance switch that needs to be set. I remain hopeful :-) Any other comments?

            • 3. Re: CMR 1-Many Performance Woes
              scoy

              No.

              It means you get to trawl thru the JBoss source to see how to configure it.

              OR

              You can spend USD10.00 and get the CMP documentation.

              I recommend the second option :-)

              Steve
              (a satisfied JBoss documentation customer)

              • 4. Re: CMR 1-Many Performance Woes
                scoy

                Please try JBoss 3.0.6.

                It's performance has been improved significantly after we did some performance profiling.

                Steve

                • 5. Re: CMR 1-Many Performance Woes
                  darryl_staflund

                  Thanks scoy,

                  Hmmm. I have 3.0.6 deployed and am using the JBoss CMP documentation as well. Transactions are implemented correctly too. Luckily I have to divert my attention to other things at work for the moment so I have some to investigate some other possibilities. I'll make sure to post any solutions if I come across them.

                  Darryl

                  • 6. Re: CMR 1-Many Performance Woes
                    darryl_staflund

                    Hi all,

                    I think I've identified issues with PostgreSQL and/or its JDBC driver that is causing all my performance problems.

                    First, according to O'Reilly's new PostgreSQL book, the following passage is written in the chapter on transactions:

                    "Without explicitly opening a transaction block, all SQL statements issued to PostgreSQL are auto-committed, meaning that the database is synchronized with the results of the statement immediately upon execution. When a transaction block is used, however, changes made to the database will not be visible to other users until the block is committed. This allows for several changes to various objects within a database to be made tentatively. They can then be either committed all at once, or rolled back."

                    This is important because when I check my PostgreSQL log I find that every query is treated as independent transactions as follows:

                    2003-02-11 22:54:25 [2162] DEBUG: StartTransactionCommand
                    2003-02-11 22:54:25 [2162] DEBUG: query: INSERT INTO actionassignment (actAssId, is_assigned, entry_id, role_id, action_id) VALUES (6080, 'false', null, null, null)
                    2003-02-11 22:54:25 [2162] DEBUG: ProcessQuery
                    2003-02-11 22:54:25 [2162] DEBUG: CommitTransactionCommand
                    2003-02-11 22:54:25 [2162] DEBUG: StartTransactionCommand
                    2003-02-11 22:54:25 [2162] DEBUG: query: SELECT actId,name, description FROM action WHERE (actId=10) OR (actId=11) OR (actId=12) OR (actId=13) OR (actId=14) OR (actId=15) OR (actId=16) OR (actId=17) OR (actId=18) OR (actId=19) OR (actId=20) OR (actId=21) OR (actId=22) OR (actId=23) OR (actId=24) OR (actId=25) OR (actId=26) OR (actId=27) OR (actId=28) OR (actId=29) OR (actId=30) OR (actId=31) OR (actId=32) OR (actId=33) OR (actId=34)
                    2003-02-11 22:54:26 [2162] DEBUG: ProcessQuery
                    2003-02-11 22:54:26 [2162] DEBUG: CommitTransactionCommand
                    2003-02-11 22:54:26 [2162] DEBUG: StartTransactionCommand
                    2003-02-11 22:54:26 [2162] DEBUG: query: SELECT roleId,name, title, description FROM role WHERE (roleId=10) OR (roleId=11) OR (roleId=12) OR (roleId=13) OR (roleId=14) OR (roleId=15) OR (roleId=16) OR (roleId=17) OR (roleId=18)
                    2003-02-11 22:54:26 [2162] DEBUG: ProcessQuery
                    2003-02-11 22:54:26 [2162] DEBUG: CommitTransactionCommand
                    2003-02-11 22:54:26 [2162] DEBUG: StartTransactionCommand
                    2003-02-11 22:54:26 [2162] DEBUG: query: SELECT COUNT(*) FROM actionassignment WHERE actAssId=6081
                    2003-02-11 22:54:26 [2162] DEBUG: ProcessQuery
                    2003-02-11 22:54:26 [2162] DEBUG: CommitTransactionCommand

                    etc.

                    All methods in my beans have a 'Required' transaction attribute associated with them so these queries SHOULD be performed within the context of a single transaction. Hence my performance problems.

                    With regard to the PostgreSQL driver, I am using the latest version just released a couple of days ago (i.e. pg73jdbc3.jar). I read in some posts toward the latter part of 2001 one, however, that the PostgreSQL driver does not support pooled database connections. I have not been able to find any more recent documentation yet to suggest that this problem has been fixed. Does anyone know if this JDBC driver is still unable to support connection pooling? If it doesn't does anyone know if this would adversely affect CMR performance?

                    And just to make sure the problem isn't with my code, I've pasted the method that takes a long time to complete below:

                    public void addGroup (SecurityGroupDO sgdo)
                    {
                    try
                    {
                    InitialContext jndiContext = new InitialContext ();

                    // Read in the names of all the home objects.
                    SecurityActionAssignmentHomeLocal actionAssignmentHome =
                    (SecurityActionAssignmentHomeLocal) jndiContext.lookup ("java:comp/env/ejb/SecurityActionAssignmentEJB");
                    SecurityRoleHomeLocal roleHome =
                    (SecurityRoleHomeLocal) jndiContext.lookup ("java:comp/env/ejb/SecurityRoleEJB");
                    SecurityActionHomeLocal actionHome =
                    (SecurityActionHomeLocal) jndiContext.lookup ("java:comp/env/ejb/SecurityActionEJB");
                    SecurityPolicyEntryHomeLocal policyEntryHome =
                    (SecurityPolicyEntryHomeLocal) jndiContext.lookup ("java:comp/env/ejb/SecurityPolicyEntryEJB");
                    SecurityGroupPolicyHomeLocal policyHome =
                    (SecurityGroupPolicyHomeLocal) jndiContext.lookup ("java:comp/env/ejb/SecurityGroupPolicyEJB");
                    SecurityGroupHomeLocal groupHome =
                    (SecurityGroupHomeLocal) jndiContext.lookup ("java:comp/env/ejb/SecurityGroupEJB");
                    PostgreSQLAdministratorHomeLocal pgHome =
                    (PostgreSQLAdministratorHomeLocal) jndiContext.lookup ("java:comp/env/ejb/PostgreSQLAdministratorEJB");

                    // Get the names of all actions and roles.
                    PostgreSQLAdministratorLocal pgAdmin = pgHome.create ();
                    Collection actions = actionHome.findAll ();
                    Collection roles = roleHome.findAll ();

                    // Create the necessary policy entries for all actions.
                    Set policyEntries = new HashSet (actions.size ());
                    Iterator actionIterator = actions.iterator ();
                    while (actionIterator.hasNext ())
                    {
                    SecurityActionLocal action = (SecurityActionLocal) actionIterator.next ();

                    // Create the necessary action assignments for all roles.
                    Set actionAssignments = new HashSet (roles.size ());
                    Iterator roleIterator = roles.iterator ();
                    while (roleIterator.hasNext ())
                    {
                    SecurityRoleLocal role = (SecurityRoleLocal) roleIterator.next ();

                    // Create an action assignment for a given action and role.
                    SecurityActionAssignmentLocal actionAssignment = actionAssignmentHome.create (action, role);
                    actionAssignments.add (actionAssignment);
                    }

                    // Create a policy entry for a given action.
                    SecurityPolicyEntryLocal policyEntry = policyEntryHome.create (action, actionAssignments);
                    policyEntries.add (policyEntry);
                    }

                    // Create the necessary group policy.
                    SecurityGroupPolicyLocal policy = policyHome.create (policyEntries);

                    // Create the target security group.
                    SecurityGroupLocal group = groupHome.create (sgdo.getName (), sgdo.getDescription (), policy);
                    }

                    catch (CreateException e)
                    {
                    throw new EJBException (e);
                    }

                    catch (FinderException e)
                    {
                    throw new EJBException (e);
                    }

                    catch (NamingException e)
                    {
                    throw new EJBException (e);
                    }
                    }


                    Thank you very much everyone.
                    Darryl

                    • 7. Re: CMR 1-Many Performance Woes
                      l.g.

                      Try this PostgreSQL jdbc driver -
                      http://sourceforge.net/projects/jxdbcon/

                      • 8. Re: CMR 1-Many Performance Woes
                        darryl_staflund

                        Well now I am getting somewhere! On the assumption that PostgreSQL is auto-committing each and every query sent by JBoss to the database even though all of them are wrapped within a single "BEGIN; COMMIT;", I asked my DBA to disable 'fsync'. This PostgreSQL feature when on, as I understand it, causes PostgreSQL to flush every query to disk after being processed until after a commit is issued. One I did this, JBoss CMP 2.x only took 12 seconds to insert 14 hundred records. A very nice performance improvement.

                        This raises some questions, however. Why is PostgreSQL auto-committing each and every query to database even though all 1400 of them are wrapped within a single 'BEGIN; .. COMMIT;'?

                        I have read in this or the JCA forum that JBoss' implementation of CMP for PostgreSQL does NOT set auto-commit to false within a single transaction block. If this is so, then perhaps JBoss' failure to turn the flag off is causing performance problems on the JBoss side of things. I say this because PostgreSQL is supposed to turn it off automatically when encountering a BEGIN; statement. If JBoss submits a BEGIN; and followed by an auto-commit=true, then this might be where the performance problems reside.

                        On the other hand, I am told by my DBA that there is a possibility that my performance problems are related to certain bugs in the way in which PostgreSQL handles shared memory.

                        Any ideas, suggestions, or comments?

                        Darryl

                        • 9. Re: CMR 1-Many Performance Woes
                          darryl_staflund

                          Problem has been fixed. The performance problems were never JBoss related. Rather, they were PostgreSQL related. Once we upgraded from PostgreSQL 7.2.4 to 7.3.2, performance improved dramatically -- from 60+ seconds to process 1400+ queries down to 5 seconds or so. Not a bad performance improvement.

                          I don't know exactly where the problem lay, but PostgreSQL 7.2.4 was definitely auto-committing each query sent to it by JBoss, even though the queries were wrapped in a transaction and even though JBoss issued a connection.autoCommit (false) at the start of the transaction.

                          Sorry for the long thread. I hope it helps others out.

                          Cheers,
                          Darryl