The art of looking at the actual SQL statements

It’s a shame that MySQL does not provide better granularity when you want to look at all SQL statements being executed in a MySQL server. I canvas that you can with the general log, but the inherit starting/stopping problems in 5.0, improved in 5.1, but I would still like to see the option on a per connection basis, or even a time period. MySQL Proxy can provide a solution here but also with some caveats.

You should however in a NON production environment, take the time to enable the general log and look the SQL Statements. Prior to looking at the SQL, monitoring of the GLOBAL STATUS variables combined with Statpack revealed the following in a 1 minute interval.

====================================================================================================
                                         Statement Activity
====================================================================================================

                     SELECT:           16,042                   267.37                8,177,050 (46.03%)
                     INSERT:            5,838                    97.30                1,826,616 (10.28%)
                     UPDATE:            1,109                    18.48                  738,546 (4.16%)
                     DELETE:            2,018                    33.63                1,374,983 (7.74%)
                    REPLACE:                0                     0.00                        0 (0.00%)
          INSERT ... SELECT:                0                     0.00                       27 (0.00%)
         REPLACE ... SELECT:                0                     0.00                        0 (0.00%)
               Multi UPDATE:                0                     0.00                        0 (0.00%)
               Multi DELETE:                0                     0.00                        0 (0.00%)
                     COMMIT:            5,708                    95.13                2,161,232 (12.17%)
                   ROLLBACK:            5,746                    95.77                3,485,828 (19.62%)

If you notice the last 2 lines, some 19% of statements executed on the server are ROLLBACK. Further analysis of the schema shows mainly Innodb tables (good as COMMIT and ROLLBACK are supported), but also some MyISAM tables.

The following is a snippet from the general log.

23 Query       select 1
                     23 Query       INSERT INTO JMS_TRANSACTIONS (TXID) values(17719)
                     23 Query       UPDATE JMS_MESSAGES SET TXID=17719, TXOP='D' WHERE MESSAGEID=16248 AND DESTINATION='QUEUE.receivemail'
                     23 Query       commit
                     23 Query       rollback
                     23 Query       select 1
                     23 Query       DELETE FROM JMS_MESSAGES WHERE TXID=17719 AND TXOP='D'
                     23 Query       DELETE FROM JMS_TRANSACTIONS WHERE TXID = 17719
                     23 Query       commit
                     23 Query       rollback

This turns out to be most interesting. These tables are use by Java Messaging Service but I observed three points.

• the ‘select 1′ is effectively a ping test to confirm the connection is still valid. MySQL provides a more lightweight COM_PING. It would be good to know if this environment using JBoss could support that.
• There is a ‘ROLLBACK’ after every command, totally redundant, and most likely part of higher level framework.
• The ‘COMMIT’ is used in conjunction with a number of statements, however when I mentioned earlier some tables were MyISAM, these were the JMS tables, so in this situation the commit is useless as this is not a transactional storage engine.

A number of decisions are needed to correct this problem, however the point of raising this is, always look at the your SQL.