Alex L. Demidov

DevOps/SRE consultant

Why Is It Always Just a Single SQL Statement Causing a Major Performance Regression?

A few weeks ago, I had to investigate a batch job that was taking more than 3 hours to run every night. The DB was the obvious bottleneck, as the job was hitting it so hard that I noticed excessive load even before the business started complaining. Before looking into the details, I assumed that the application code was doing some loops internally, retrieving mostly the same data again and again. I started preparing myself to dive into the code for a week to untangle data flows, imagining the horrors of multi-page SQL statements.

But “Premature optimisation is the root of all evil”, so first things first: enable detailed monitoring and collect query statistics for a day. The next morning, there is some data: the code is hitting mostly a single table with a simple query but with WHERE on a column without an index. Add an index, maybe it will help improve the performance before I have to dive into the code.

The next morning, I check the DB graphs, and there is no load at all. Did the job run? Did someone disable it? Did I change something, causing the job to crash?

Checking the application logs. The job did run. And completed successfully. In 10 minutes. One single index reduced run time from more than 3 hours to 10 minutes. The classic “one hit with the hammer but you need to know where to hit”.

On the other hand, I’m trying to imagine what someone who “doesn’t know where to hit” and has no visibility into the database and application performance would do to solve this issue. Just crank up the instance size? I suspect they would end up paying ten times more.

Building Vagrant-based Development Environment

Over the course of the last few months I have built three different custom Vagrant boxes to create local development environment for two different applications — one is WordPress based and another is Rails one with a few PHP parts.

The problem which Vagrant solved was that both applications are too complex to setup manually. Even when working with WordPress developers didn’t work locally but instead used to edit files directly on live server and even when we imported all code into git they started using integration server for day-to-day development and their workflow looked terrible — change a line, commit, push, wait for deploy script to run, check integration server for results, repeat. Moreover, as a result of this workflow git history looked ugly — myriad of one-line commits with no commit messages, which are painful to merge. For Rails app we needed some CSS/HTML tweaks and there is just no way average front-end developer can setup Rails development environment on Windows.

At first I thought about distributing binary Vagrant box but I still needed to distribute application source code as git repository and Vagrantfile to configure sharing and I was too lazy to setup password protected directory on web server to download binary box and hand out all credentials to individual developers (Vagrant Cloud for organizations hadn’t been available yet). So I decided to make one single git repo with Vagrant configuration and cookbooks and source code repo included as submodule.

It was a while since I did chef cookbook development so I googled a lot at first trying to find what is the best current approach and which tools to use. Cookbook development completely changed over last year or two — there are now test-kitchen, berkshelf, serverspec etc and all these tools are changing very fast — almost any tutorial older than a few months is obsolete.

So far I have found following blog posts as the most current:

In my setup I have followed the second one and cross-checked with the first article. I chose to include in my toolbox test-kitchen, berkshelf, serverspec, chefspec, foodcritic, rubocop and wrap everything with guard (but later disabled test-kitchen run from guard as it was failing). In the beginning I started preparing custom Vagrant base box with veewee but dropped it as I didn’t really need anything custom and standard chef/debian box from vagrantcloud.com worked well.

My main repo has very simple structure — Gemfile with berkshelf, Berksfile with all necessary cookbooks, Vagrantfile and INSTALL file with step-by-step instructions for developers. In www sub-directory I have site source code as git submodule and in cookbooks sub-directory all depended cookbooks vendored using berks vendor cookbooks. At first I used to include my own cookbooks as git submodule too into site-cookbooks but as berks vendor retrieves them anyway I dropped this. Also I decided not to use vagrant-berkshelf plugin to maintain cookbooks as it is deprecated.

For each application I created individual cookbook and one cookbook for common configuration. Each cookbook has own git repo and follows standard layout created by berks cookbook. I have also decided to rely on community cookbooks for all dependencies like MySQL, PHP etc, even though I didn’t do much customization but this decision caused a bit of pain — I had to fork cookbooks for MySQL and monit to support Debian squeeze and had to use alternative cookbook for PHP as phpmyadmin cookbook depends on it. Each cookbook has multiple recipes: for Vagrant setup, for integration server setup and for live server setup as there is some differences between them — SSL support and while integration server runs php-fpm live server still uses mod_php.

At first I followed quite strict TDD/BDD loop — create serverspec tests, then chefspec and then write recipe but after a while dropped chefspec tests as I find writing expect(chef_run).to include_recipe('apache2') and then include_recipe 'apache2' a bit boring. Also running kitchen converge && kitchen verify is quite slow even with a lot of RAM and on SSD disk. I tried to speed up things by switching to LXC but kitchen-lxc seems to be broken and unsupported and using vagrant-lxc with test-kitchen isn’t documented very well and requires building LXC base boxes manually using outdated instructions — some links to configuration templates are 404 and after you build base boxes recent Vagrant complains about outdated box format. My attempts to use more up to date scripts to build base box failed as these scripts just segfaulted on me and I didn’t have time to fix them as manually built base boxes already working. Another issue is that my Linux Mint box had sudo configuration setting which caused vagrant-lxc to fail when used with test-kitchen and a couple weeks passed before I found time to find a solution so all cookbooks were developed slowly using VirtualBox.

But overall development went quite smoothly except for few PHP/WordPress surprises in the end — e.g. PHP with short_open_tag switched fails with syntax error pointing to the end of huge 5K LOC .php file without any hint of real error cause or WordPress shows just blank front page without any error messages in error logs if some plugin fails or missing. But real adventure was still ahead. When all cookbooks were ready and fully tested locally on Linux and Mac OS X it was time to deploy to Windows boxes where everything failed just at the very beginning — Vagrant was launching VirtualBox VMs but unable to ssh into them. Few days of remote debugging using email and I had found that even vagrant init hashicorp/precise failed to work on Windows so I got idea and tried to switch to 32-bit OS image which worked. Later I got RDP access to Window 8 box and launched VirtualBox directly which complained that VT-x is disabled (it needs to be enabled in BIOS and this feature is unavailable on Celeron processors) and it can’t launch 64-bit image. Once I switched images to 32-bit all Windows users were able to use them without much problems, except occasional cases when developers didn’t read documentation and forgot to use git clone --recursive and similar issues.

Another quite problematic issue with Windows was that it is impossible to create symbolic links on shared file system with default settings and Rails app were deployed capistrano style and relied on symbolic links heavily. I had to revamp whole recipe for Rails app and remove all symbolic links to get it working on Vagrant under Windows. Another Rails specific issue is that rvm cookbooks needs special recipe rvm::vagrant to be included before any other recipe if it is run in Vagrant VM.

WordPress Site Performance Optimization

Spent about a week working on optimizing performance of WordPress-based web application. While site already had some optimizations in place, like W3 Total Cache backed by APC and mod_pagespeed installed, there still were complaints that site loads very slow.

Before making any action I started by measuring actual performance and gathered metrics using New Relic and Chrome Developer Tools Audit Tab. New Relic showed a few of critical insights into performance troubles.

First one was two widgets in the footer of every page each making requests to external API services taking on average ~600ms one and ~1500 ms another. As the second service was our own custom service I quickly optimized it by adding counter cache field to table instead of making select on depended records on each request and request time went down to around ~150 ms. But these requests were still made on every page load so I patched both widgets to cache responses from external API in memcached for 5 minutes. Average page generation time went down to around ~800 ms.

Another thing to optimize was W3 Total Cache. First I turned off its minify option as it was sometimes taking up 2-3 seconds according to New Relic. Next I switched cache storage from APC to memcached as APC was constantly reset every minute by some rogue code somewhere on this server: grep -r apc_clear_cache showed about hundred of matches. This issue also affected PHP opcode caching so I decided to switch to Zend OPcache for opcode caching. For page cache I choose to switch from memcached storage to extended disk so if page was cached then Apache would serve it directly without hitting any PHP code. As database queries were taking insignificant percentage of all page generation time I switched DB cache completely off to avoid PHP overhead and instead cranked up MySQL own query cache memory limits.

With all these optimizations page generation time stabilized around ~600ms against ~2500 ms week ago and I called it a day – I don’t think I can squeeze more performance out of WordPress without going through analyzing performance impact of each plugin.

The next step in the site optimization was tuning of mod_pagespeed settings. At first it looked like it was not working at all. After checking mod_pagespeed logs I have found that it doesn’t work with SSL by default and we have https-only site. Another obstacle with which I have spent good half hour is that W3 Total Cache page cache interferes with mod_pagespeed, looks like later ignores static HTML files. After that I have enabled most of mod_pagespeed CoreFilters, focusing on CSS and JS files optimization, as we had about 30-40 assets of each kind, and was able to reduce number of external CSS/JS down to 9-10 per page. I have also tried to optimize page loading by using filter defer_javascript which moves JS files down to page footer but had to turn it off later as it broke some JS navigation menus. Overall page load speed went down from around 10 seconds to 5 seconds on average.

Octopress Revival

Resurrected my standalone blog for the third time, this time again on Octopress and still on 2.0 version. I didn’t intend to do this but there is still no good blogging platform with code highlighting support.

I set it up pretty quickly but the first problem was that I wanted to keep old content but I didn’t have source code for it anymore. Converting by hand seemed tedious so I thought about hiring someone on oDesk but then, after a few Google searches I found a tool to convert HTML back to markdown — reverse_markdown ruby gem. At first attempt it did no conversion but after stripping all HTML code around actual post content (the most important is to remove article tags around) it produced nice markdown which I put back into Octopress.

After initial import I did some cleanup — removed unnecessary /blog prefix from post permalinks, fixed links in old content pointing to my old-old MovableType blog and imported static files into Octopress. To check all links I installed link-checker ruby gem — it works pretty fine but seems to be having problems with some https:// links.

Once all content was in good shape I tweaked CSS colors back to my old palette, added Stack Exchange badge, enabled Disqus comments, updated Google Analytics JavaScript to latest universal code.

After comparing generated HTML with old blog using diff I have found a bug in Octopress: canonical link for categories pages is broken by default — has missing /, see Octopress issue #949 for fix. Once I was satisfied with content I deployed it to server using rsync.

There is currently Octopress version 3.0 in development and it is close to final release but it seems to be quite different from version 2.0 in its concept and as its author says:

For those currently using Octopress, it will be a while before the new releases can compete with the features of the old version.

Hunt for the Bug

Spent three days last week hunting for mysterious bug which caused factory_girl factories randomly fail with Trait not registered: class message during full test suite run, but when you run all controller or model tests separately — everything is fine and all tests which were failing during full run worked perfectly.

At first I ignored this issue — I had just added two new factories, which coincidentally used class parameter in their definition to specify generated class explicitly, and I needed these factories to test code I was working on and I though that I’ll fix or just remove these factories later.

But as it usually happens it wasn’t simple as I thought. Suddenly I discovered that tests started failing with the same symptoms on common develop branch and not on only topic branch. And I broke tests already in two other places, so clean up was really needed.

First two days I spent trying to find out what happening in factory_girl internals using old-school print logging and later pry-debugger but without much success except that I was able to locate single spec file in spec/workers/ which caused failure of all consecutive factory calls. Then I started looking at git history trying to find commit which introduced this issue. Luckily, in spite of heavy rebasing and few backported commits, my master branch didn’t have this issue and I was able to pinpoint this to single commit. At first glance this commit looked almost innocent — it just extracted code from model and moved it to app/workers/. But there were two tests added to failing spec file and they were the tests which caused cascading failure of all remaining tests in suite. After reviewing the code under test I had found that real culprit was memory leak debugging code I quickly slapped in without running tests:

1
2
3
4
5
  counts = Hash.new { 0 }
  ObjectSpace.each_object do |o|
    counts[o.class] += 1
  end
  counts.reject! { |_k, v| v < 100 }

It seems that FactoryGirl::DefinitionsProxy undefines all methods including class and method_missing in this class adds any calls as traits to factory so walking through ObjectSpace and calling class on every object wreaks havoc on factories.

Сборка русской версии Movable Type

Для сборки руссифицированной версии Movable Type нам опять понадобятся исходники из svn-репозитария. Делаем чекаут, как описано в предыдущей статье о работе с файлом перевода и прикладываем к полученным исходникам патч patch-rubuild.gz, который добавляет возможность сборки русской версии.

Следующим шагом вносим в исходники все необходимые изменения для поддержки русского языка:

  • patch-rudate41.gz — добавляет русский формат дат
  • patch-rudirify41.gz — добавляет русские символы в таблицы преобразования заголовков статей в имена файлов (в отличии от патча Алексея Тутубалина изменяется также и Javascript код, а преобразование русских символов в латиницу сделано в соответствии с ГОСТ 7.79-2000)
  • patch-nofollow.gz — добавляет поддержку тэга необходимого для российских поисковиков (автор Алексей Тутубалин)
  • patch-monday-mt41.gz — делает первым днем недели в календаре понедельник (автор Алексей Тутубалин)

После внесения изменений в код и шаблоны осталось добавить собственно файл перевода lib/MT/L10N/ru.pm ( перевод проекта movable-type.ru, либо мой, менее полный перевод), файл стилей mt-static/styles_ru.css и два HTML-файла — index.html.ru и readme.html.ru (они есть в репозитарии русской версии Movable Type на Google Code). Файл перевода необходимо обработать в соответствии с инструкциями в предыдущей статье. В завершении можно изменить некоторые настройки по умолчанию (часовой пояс, кодировки, ссылки на новости, портал и техподдержку) для собираемого пакета, отредактировав файл build/mt-dists/ru.mk.

Сделав все необходимые изменения выполняем сборку пакета MTOS:

env LANG=C ./build/exportmt.pl --local --pack=MTOS --lang=ru --prod

В результате выполнения данной команды получим два архива с русской версией Movable Type — MTOS-4.1-ru.tar.gz и MTOS-4.1-ru.zip.

Работа с файлом перевода Movable Type

Совпадение, но через два дня после публикации последней статьи на тему руссификации Movable Type, вышел перевод от проекта movable-type.ru. В сравнении с моим переводом, он более полный, но делался, судя по всему, по французскому файлу трансляции от версии 4.0 и в нем отсутствует более 300 строк, а также полтора десятка строк остались на французском.

Для того, чтобы синхронизировать файл перевода с текущим релизом (а также будущими релизами) и добавить в него отсутствующие строки, нужен полный комплект исходников Movable Type из svn-репозитария — в них пристутствует набор скриптов для манипуляций с файлами переводов (для работы скриптов нужен perl и набор unix-утилит – shell, awk, find и т.д.). Сначала делаем чекаут исходников из репозитария:

svn co https://code.sixapart.com/svn/movabletype/latest mtos-latest

После выполнения данной команды в каталоге mtos-latest будет три подкаталога: dev, stable и release. Нам нужен подкаталог release, в котором находится последний релиз Movable Type с которым мы будем работать. Первым делом кладем наш файл перевода ru.pm в подкаталог lib/MT/L10N/. Следующим шагом запускаем собственно генерацию обновленного файла перевода из каталога release:

sh build/l10n/make-l10n ru

В результате работы данного скрипта в каталоге /tmp будет сгенерировано четыре файла:

  • ru-base.pm — файл со всеми строками трансляции (в том числе дублирующиеся строки)
  • ru-nodupe.pm — файл с удаленными дубликатами строк
  • ru-old.pm —строки трансляции которые более не используются
  • ru.pm —новый файл перевода

В новом файле перевода /tmp/ru.pm будут добавлены отсутствующие строки перевода (отмечены комментарием «Translate – New») и будут отчемены строки с регистром перевода отличающимся от оригинала — например, переводы следующего вида:

'video' => 'Видео'

Этот файл уже готов к использованию, но для полноценной поддержки русского языка я сделал дополнительный фильтр ru-filter.pl, через который надо пропустить файл перевода:

cat /tmp/ru.pm | perl ru-filter.pl > lib/MT/L10N/ru.pm

Данный фильтр делает следующее:

  • отмечает комментарием «# Translate – No translation» непереведенные строки, в которых оригинал и перевод совпадают
  • отмечает комментарием «# Translate – No russian char» строки перевода в которых не встречаются русские буквы
  • отключает строки с пустым переводом
  • добавляет perl’овый код для правильной поддержки множественного числа

Поддержка множественного числа сделана через переопределение функцииquant из Locale::Maketext. Теперь второй и третий параметры этой функции принимают формы слова для значений числительного от 2 до 4 и от 5 до 0 соответственно. Таким образом можно писать «[quant, _1,минута,минуты,минут]» и соответствующий текст будет генерироваться как «1 минута, 2 минуты, 5 минут» вместо «1 минута, 2 минут., 3 минут.»

Руссификация Movable Type 4.1

Продолжаем работу с Movable Type. Руссификацию пришлось делать в два захода. На первом заходе, после предварительного гугленья, был применен рецепт для руссификации Movable Type версии 4 от Алексея Тутубалина с небольшими изменениями:

  • приложен патч patch-monday-mt41.gz для того чтобы в календаре неделя начиналась с понедельника
  • приложен патч patch-dirify.gz для конвертации русских символов в заголовках статей в латиницу при генерации имени файла
  • приложен патч patch-nofollow.gz для поддержки тэга для Яндекса

Патч patch-rudate.gz не прикладывал, но посмотрев в него, сделал свой. Вместо того, чтобы использовать итальянский формат, добавил русский в список форматов, изменив lib/MT/Util.pm и tmpl/cms/cfg_entry.tmpl. Изменен также и формат отображения — вместо 24.03.2008 будет Март, 24 2008. Патч patch-rudate41.gz прилагается.

Далее последовал наиболее нудный этап — перевод шаблонов. Разбор со скриптом Алексея Тутубалина для экспорта/импорта шаблонов я оставил на потом (этот скрипт был сделан до выхода версии 4.1 и неизвестно как он с ней работает, к тому же он требует установки плугина TemplateInstaller), поэтому шаблоны перевел вручную через админку Movable Type. Хотя шаблонов около полусотни, но сами они немногословны и переводить можно не все, а только те, которые реально используются. Поэтому первые результаты появился сравнительно быстро, но в процессе перевода увлекся файн-тюнингом оформления и внес слишком много изменений в шаблоны, так что собравшись создавать блог для своей SO, обнаружил что мне надо либо вычищать свое оформление, либо возвращаться к стандартным шаблонам и переводить их опять с нуля.

Немного поразмышляв, решил выбрать другой подход. В Movable Type есть в наличии полная инфраструктура для локализации базирующаяся на perl’овом Locale::Maketext и документация рекомендуют именно этот подход. Проект movable-type.ru после выхода версии 4.0 в августе 2007 вроде бы огранизовал коллективную попытку сделать русский перевод и месяц назад даже заявлена 90% готовность, но реальных результатов пока не наблюдается. Конечно объем текста в более чем 4 тысячи строк на первый взгляд выглядит ужасающе, но ничто не мешает переводить текст по частям, например, для начала только те строки, которые используются в самих блогах, а не в админке.

За пару вечеров у меня был готов перевод следующих компонентов используемых в опубликованном блоге:

  • шаблоны default_templates/*.mtml которые используются при генерации шаблонов нового блога
  • шаблоны plugins/WidgetManager/default_widgets/*.mtml для widget’ов
  • php-скрипты динамической публикации

Все это занимает где-то чуть более 600 строк ( ru-published-only.pm). Данный файл необходимо переименовать в ru.pm и положить в lib/MT/L10N/, при этом русский язык автоматически станет доступен для выбора в профиле пользователя. Стоит иметь в виду, что перевод фраз в шаблонах на русский производится в момент генерации шаблонов и только если у пользователя выбран русский язык в профиле. Если блог уже создан, то можно перегенерировать шаблоны заново, зайдя в своем блоге через меню «Design» → «Manage Templates» → «Refresh Blog Templates». При перегенерации большинство новых руссифицированных шаблонов будут иметь русские имена и у меня лично слетели Archive Maps и наборы widget’ов. Нужно будет их пересоздать, предварительно удалив все старые шаблоны и widget’ы.

Все остальное пока находится в процессе перевода, хотя наиболее часто используемые части админки уже переведены практически полностью (можно скачать Файл перевода). В качестве основы для этого файла взят es.pm, поэтому непереведенные строки будут по испански. Также добавлен скрипт mt_ru.js который содержит локализованные строки для JavaScript и локализованную таблицу для динамической dirtif’икации заголовков в имена файлов. Файл стилей styles_ru.css содержит одну строчку — модификация ширины колонок в виджете календаря.

По мере дальнейшего перевода я планирую выкладывать обновленную версию файла ru.pm, следите за обновлениями.

Ускорение Movable Types ( Apache и FastCGI )

После установки Movable Type обнаружилось что работа с его админкой (CMS) достаточно некомфортна из-за её существенной тормознутости — время загрузки главной страницы составляет около 15 секунд. Впрочем, это не удивительно, поскольку админка реализована как достаточно тяжелый perl’овый скрипт со множеством зависимостей которые при работе в режиме стандратного CGI подгружаются при каждом HTTP-запросе.

Первой мыслью было попробовать запустить его под mod_perl, который у меня уже есть, но как оказалось Movable Type поддерживает только mod_perl 1.x, а я уже третий год как переехал на Apache 2.x. Поэтому пришлось обратиться к альтернативном варианту — FastCGI, отличие которого от классического CGI именно в том, что скрипт обслуживает не один, а множество HTTP-запросов, чем минимизируются временные затраты на запуск и инициализацию скрипта.

Сначала обеспечиваем поддержку FastCGI в Apache — это делается с помощь модуля mod_fastcgi (или альтернативная реализация mod_fcgid). Ставим модуль и подключаем его в httpd.conf.настройки для mod_fastcgi:

LoadModule fastcgi_module libexec/apache22/mod_fastcgi.so
<IfModule mod_fastcgi.c>
  AddHandler fastcgi-script .fcgi
  FastCgiIpcDir /var/run/fcgidsock/
</IfModule>

настройки для mod_fcgid:

LoadModule fcgid_module libexec/apache22/mod_fcgid.so
<IfModule mod_fcgid.c>
  AddHandler fcgid-script .fcgi 
  SocketPath /var/run/fcgidsock/
</IfModule>

Сам Movable Type начиная с версии 4 поддерживает работу через FastCGI из коробки, поэтому для его настойки достаточно указать для каталога где находятся скрипты mt*.cgi следующую директиву:

AddHandler fcgid-script .cgi

или

AddHandler fastcgi-script .cgi

После включения данной опции тестирование с помощью ApacheBench показало на моей домашней машинке ускорение более чем на порядок — с 0.75 запросов в секунду до 15. Но особого ускорения при работе с админкой не прозошло. Налицо классический случай «premature optimization», которая «root of all evil» © C.A.R. Hoare.

Поэтому пришлось все-таки более внимательно посмотреть в YSlow и последовательно применить предлагаемые рекомендации. Основная проблема оказалась в большом количестве объектов на странице и как следствие, большом количестве HTTP запросов (около 50 в данном случае), причем большинство запросов были If-Modified-Since на файлы из mt-static, в осовном изображения. Лечиться это добавлением заголовков Expires для каталога mt-static с помощью mod_expires:

ExpiresActive On
ExpiresDefault "access plus 1 month"

С включением данной опции броузер перестал обращаться к каждой картинке при каждой загрузке страницы, что сократило количество запросов с полусотни до ровно одного — обращение собственно к mt.cgi. Общий объем передаваемых данных также сократился с 100Kb (уже с учетом включеной компрессии для text/*) до 10Kb. Общее же время загрузки страницы сократилось с 15 секунд до 5-6 секунд по таймеру YSlow и до 3-4 секунд по секундомеру с отключеным FireBug‘ом и YSlow.

Достигнутый результат меня вполне устроит и тему оптимизации можно отложить. Дальше нужно будет заниматься уже переводом на русский и переносом на боевой сервер в тесный jail. А пока в процессе первых дней эксплуатации выяснилось пара нюансов. Во-первых, не все скрипты MT работают в режиме FastCGI, поэтому лучше использовать следующие настройки подсмотренные в документации Movable Type:

<FilesMatch "^mt(?:-(?:comments|search|tb|view))?\.cgi$">
     AddHandler fcgid-script .cgi
</FilesMatch>

Во-вторых, процесс mt.cgi со временем может разрастаться до достаточно неприличиных размеров (более 100 Mb) и поэтому лучше настроить mod_fastcgi так, чтобы он переодические его перезапускал:

FastCgiConfig -maxProcesses 10 -killInterval 3600

и для mod_fcgid

ProcessLifeTime 3600
   MaxProcessCount 10
   MaxRequestsPerProcess 500

И в третьих, при работе через FastCGI возникают неудобства с изменением кода MT на ходу — необходимо постоянно перезапускать mt.cgi чтобы он перечитал измененные модули.

Продолжение следует