Включение лога долго выполняющихся запросов в MySQL (настройка log-slow-queries) не спасает при необходимости выявления транзакций, находящихся длительное время в незакрытом состоянии. Транзакции, внутри которых были изменены данные, но которые остаются висеть без коммита, достаточно трудно выявить и сопоставить с источником (в списке активных запросов по "SHOW PROCESSLIST" они не видны), в то время как они могут привести к разнообразным проблемам с блокировками и неудачному завершению других операций после истечения таймаута.

Для отладки проблемы обычно определяют какая из транзакция блокирует остальные. Затем, определяется TCP-порт для проблемного соединения, запускается сниффер и используется утилита mk-query-digest для создания лога выполняемых запросов.

В MySQL 5.1, при использовании InnoDB plugin, блокирующую транзакцию выявить значительно проще - поддерживаются специальные INFORMATION_SCHEMA таблицы, запросив которые можно определить идентификатор нити, обрабатывающей висящую транзакцию, после чего найти этот идентификатор в выводе "SHOW PROCESSLIST" и увидеть имя хоста и номер порта инициатора проблемы.

В более ранних ветках MySQL и во встроенном движке  InnoDB (не InnoDB plugin) найти проблемное сетевое соединение не так просто, можно лишь субъективно оценить вывод "SHOW INNODB STATUS", выбрав старейшую транзакцию, находящуюся в статусе ожидания или блокировки. Иногда таким образом удается угадать проблемную транзакцию, а иногда - нет.

Чтобы автоматизировать выявление проблемных транзакций написан небольшой скрипт, который запускается каждые 30 секунд, смотрит статус и находит проблемные позиции в списке. Для проблемных транзакций выявляется номер порта, запускается сниффер и сохраняется лог.

   #!/bin/bash

   # Begin by deleting things more than 7 days old
   find /root/tcpdumps/ -type f -mtime +7 -exec rm -f '{}' \;

   # Bail out if the disk is more than this %full.
   PCT_THRESHOLD=95
   # Bail out if the disk has less than this many MB free.
   MB_THRESHOLD=100
   # Make sure the disk isn't getting too full.
   avail=$(df -m -P /root/tcpdumps/ | awk '/^\//{print $4}');
   full=$(df -m -P /root/tcpdumps/ | awk '/^\//{print $5}' | sed -e 's/%//g');
   if [ "${avail}" -le "${MB_THRESHOLD}" -o "${full}" -ge "${PCT_THRESHOLD}" ]; then
      echo "Exiting, not enough free space (${full}%, ${avail}MB free)">&2
      exit 1
   fi

   host=$(mysql -ss -e 'SELECT p.HOST FROM information_schema.innodb_lock_waits w INNER JOIN
      information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id INNER JOIN information_schema.processlist p
      on b.trx_mysql_thread_id = p.ID LIMIT 1')

   if [ "${host}" ]; then
      echo "Host ${host} is blocking"
      port=$(echo ${host} | cut -d: -f2)
      tcpdump -i eth0 -s 65535 -x -nn -q -tttt port 3306 and port ${port} > /root/tcpdumps/`date +%s`.tcpdump &
      mysql -e 'show innodb status\Gshow full processlist' > /root/tcpdumps/`date +%s`.innodbstatus
      pid=$!
      sleep 30
      kill ${pid}
   fi

Посмотрев лог ".innodbstatus" и убедившись, что это не ложное срабатывание, проанализировать активность связанного с незакрываемой транзакцией соединения можно выполнив команду:

  mk-query-digest --type=tcpdump --no-report --print файл.tcpdump

В  mk-query-digest также удобно использовать опцию --timeline, отображающую последовательность запросов в наглядном виде.

URL: http://www.mysqlperformanceblog.com/2011/03/08/how-to-debug-.../
Обсуждается: http://www.opennet.dev/tips/info/2557.shtml