Clients with an existing application sometimes ask me to fix bugs, improve efficiency by speeding up the application, or add a new feature to some existing software. The first stage of this is researching the original code – so-called reverse engineering. With SQL databases, it is not always immediately obvious which SQL queries MySQL executed – especially if these queries were generated by a framework or some kind of external library.
In this article, I will talk specifically about MySQL and present a common optimization use case which might come in handy if you run into a similar problem one day.
MySQL allows you to save all queries into a log.
Open MySQL console:
mysql --user=USERNAME --password=PASSWORD
This turns on the log:
set global general_log = "on";
This saves it to a table:
set global log_output = "table";
To view the logs you’ve saved:
select * from mysql.general_log;
To compress your logs:
However, viewing logs in the MySQL’s console is not as convenient as it could be because:
- There are no highlighting or formatting options
- It’s hard to locate problematic queries among the huge list you get from running parallel processes.
As I often work with logs, I developed a tool called “Beaver MySQL logger” to optimize and make them easier for the user to analyze. With this tool you can:
- Turn logging on/off
- View logs in a nice interface
- Search logs
- “Explain” queries
- Clear logs
You can see a screenshot of the program below:
Example of a Client Optimization Project
I was asked by one of my Upwork clients to help with the optimization of their event listing page which was loading too slowly.
After I turned on the logging, I saw around 680 SQL queries were executing per page load. I found that each query was loading separately leading to 100 events per page and each event was additionally loading like this:
select * from user where id = N
select * from role where id = N
select * from country where id = N
select * from city where id = N
select * from category where id = N
Why was this happening? The project was using the Yii framework, which meant that the code for data access was using the syntax below:
$event->user->name; $event->country->title; $event->city->title; $event->category->name; $event->role->name;
$event is a row in the table.
This means the table had to execute 500 additional queries which reduced efficiency and affected the overall performance.
How To Fix It
Combining the necessary values into a single query will reduce the amount of needed server work load:
select * from event left join user on user.id = event.user_id left join country on country.id = event.country_id left join city on city.id = event.city_id left join category on category.id = event.categroy_id left join role on role.id = user.role_id
Since the project was developed with the Yii framework, it may be fixed by using the following enumeration table for the names in the criteria:
$criteria = new CDbCriteria([ 'width' => ['user.role', 'country.city', 'category'] ]);
Hooray! It will now be running 500 fewer queries per request!
After studying the logs further, I also found that for each menu item in the application the SQL query was made to check each access level like so:
select level from acl where role_id = N and page_id = N
This access level check generates around 150 added queries per page load! The easiest way to fix this is to use the cache for the menu widget.
Before the project, the page took 1100ms to load. After optimization, 130ms.
Logging systems are multi-functional and can also be used to research business trends or find bugs in other systems. By following this simple process, we reduced the number of SQL queries from 650 to 150. While this is a large gain, it’s far from perfect.
A more comprehensive guide to MySQL optimization in general can be found in the following three posts:
What are your optimization success stories? Anything you can share? Let us know!