Analyse Sugar Queries

Database performance can have a huge affect on the performance of a web application, especially one as large and complex as SugarCRM. Tuning your database to deal with Sugar’s many queries can have a huge impact on its performance. But how do you find out what exactly Sugar is doing, and which queries are causing a bottleneck?

Sugar comes with an option in the logging section of system settings called “log slow queries”. This option adds an extra entry to the log file when a query takes longer than a certain (configurable) threshold to execute. While this is useful to a point it doesn’t really help an admin to find out what queries are using up the most database time. For one thing some queries, while executing very quickly, are repeated many, many times. When you add these repetitions together they can amount to a surprisingly large amount of time.

I wanted a tool to give me a realistic analysis of the queries running on the various Sugar installations I deal with. Finding nothing available online I “rolled my own” and have decided to make my code available for others to use.

Here’s an example of the analysis from my script:

That was an extract from the log when opening a detail view of an object in a custom module. From the analysis I could see that just over four seconds of the time taken to render the page was taken by database time. From that I was able to change some queries’ syntax to make them run faster, and add indexes and other optimisations to the database where queries couldn’t be changed, eventually cutting the db time down by almost 75%.

You may wonder what “unknown time” means in the statistics. This is db time accounted for by Sugar where no query was output to the log. For example, you’ll see entries like this in your log file:

The easiest way to get a log extract for a specific action (e.g. fetching a contact list) is as follows:

  1. delete the sugarcrm.log file
  2. perform the action (i.e. open the contact list view) in a browser
  3. rename the log file to something like contact-list.log

You can then run the analysis script against that particular log file using the -f parameter. Note that the script is currently only designed to handle Sugar’s standard log format.

The options available are:

  • Sorting – sort by individual query time, combined time of repeated queries or number of times a query was run
  • Untimed queries – include queries run where Sugar didn’t write a corresponding execution time to the log
  • Thresholds – choose how many queries to display, and the minimum query time

Running the script

Before you begin you will need to set Sugar’s logging level to “debug” so that it logs the details for every query run.

The script needs to be run from a command line, as below:


./analyse_sugar_queries.php -f contact-list.log -s combined -mt 0.001

Download the script using the link below:

analyse_sugar_queries

If you’d like to see any other features added to the script I’d love to hear about them, and any feedback on how the script has helped you analyse your SugarCRM queries 🙂


5 thoughts on “Analyse Sugar Queries

  1. Gaurav Sharma

    Hi,

    Thanks for the script. How do I use it?

    • David

      Run it from a command line, as in the blog entry. You need to chmod +755 the script before, and if your php location is not /usr/bin/php then edit the first line and correct the location.

  2. Jxn

    Thanks for the script. I’m working on optimizing tables right now, however, running the script I received a division by zero error.

    I haven’t dug in yet to see if I can figure it out yet, but here is the command / error:

    # ./analyse_sugar_queries.php -f sugarcrm.log -s combined -mt 0.001

    Warning: Division by zero in /home/murthaj/analyse_sugar_queries.php on line 242

    Warning: Division by zero in /home/murthaj/analyse_sugar_queries.php on line 243

    —– Query Analysis —–

    sorting by: combined
    log file used: sugarcrm.log
    log entries read: 5763
    max queries to display: 200
    min time to displayed: 0.001
    total queries:
    unique queries: 0
    slowest query: 0
    slowest combination: 0
    average query time: 0
    average combined time: 0
    total unknown time: 0
    total db time: 0

  3. Jxn

    oops, I figured it out. Apparently you need to set logging mode to DEBUG in order to use the tool. Thanks!

    • David

      Ah yes, I should have mentioned that in the blog entry. Thanks for pointing that out, I’ll update the blog and script.

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes:

<a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code class="" title="" data-url=""> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong> <pre class="" title="" data-url=""> <span class="" title="" data-url="">