Dive into MySQL Error (YAPC::Tokyoバージョン)

2019/01/26 YAPC::Tokyo 2019

Transcript

1. Dive into MySQL Error 第二雑学研究部、略してダイブ 2019/01/26 yoku0825 YAPC::Tokyo 2019
2. Dive into MySQL Error 第二雑学研究部、略してダイブ “MySQLの” エラーの仕組みを考えるセッションです “MySQLのエラー” をどう回避するか、ハンドルするか、という話は 出てきません ‐ 本トークはPerl成分を含みません 変数の頭に $ がつかない言語にご注意ください ‐ 1/83
3. Chiba.pmの 方から来まし た 2/83
4. Chiba.pm の “m” は 3/83
5. MySQL の “m”！ 4/83
6. ※諸説あ り 5/83
7. じゃあ…準備 はいいですか ね？ 6/83
8. せーの 7/83
9. ＼こんに千葉！／ (c) @hokke_mirin 8/83
10. ( ´-｀).oO（東 京の西側から来た なんて言えない 9/83
11. ＼こんに千葉！／ (c) @hokke_mirin yoku0825＠とある企業のDBA オラクれない ‐ ポスグれない ‐ マイエスキューエる ‐ Perl Monger!! ytkit - Yoku-san no ToolKIT Contributor of innotop ‐ 生息域 Twitter: @yoku0825 ‐ Blog: 日々の覚書 ‐ 日本MySQLユーザ会 ‐ MySQL Casual ‐ 10/83
12. MySQLのエ ラーの話をし ます 11/83
13. 存分にダイブ しましょう 12/83
14. MySQLのエラーってこんなやつ ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2) 13/83
15. MySQLのエラーってこんなやつ DBIx::Sunny connect('database=isucon2;host=127.0.0.1;port=3306',' isucon2app',...) failed: Can't connect to MySQL server on '127.0. 0.1' (111) at /home/yoku0825/git/isucon2/webapp/perl/lib/Isucon2. pm line 29. 14/83
16. 「MySQLのエラー」と言ってもいくつかあって MySQLサーバーの異常 MySQLサーバーからクライアントに返すネガティブな応答 クライアントライブラリーの異常 15/83
17. 「MySQLのエラー」と言ってもいくつかあって MySQLサーバーの異常 MySQLサーバーからクライアントに返すネガティブな応答 クライアントライブラリーの異常 16/83
18. MySQLサーバーからクライアントに返すネガティブな応 答 認証失敗 権限の不足 SQLシンタックスエラー デッドロック検出 タイムアウト ..etc. 17/83
19. 余談 “ER_LOCK_DEADLOCK”, 1213, “Deadlock found when trying to get lock; try restarting transaction” 「デッドロックした」んじゃなくて、「デッドロックになり そうな気配がしたのでロールバックした」という意味のネガ ティブメッセージ bugs.mysql.comとかで「デッドロック」というと「本当に デッドロックしてタイムアウトするまで身動きが取れなく なってるやつ」のこと 18/83
20. MySQLのエラーパケットの構成 19/83
21. エラーコード分類 range error_kbn 1..999 グローバルエラー 1000..1999 サーバーサイドエラー 2000..2999 クライアントサイドエラー (*) 3000..4999 サーバーサイドエラー 5000..5999 X Pluginのエラー 10000..49999 システムメッセージ 50000..51999 サードパーティ用 (*) libmysqlclient.soの場合 MySQL :: MySQL 8.0 Reference Manual :: B.1 Error Message Sources and Components 20/83
22. ( ´-｀).oO（どうせな ら「リトライして成功す る可能性のないエラー」 も体系にしてくれると嬉 しかったのに… 21/83
23. 「MySQLのエラー」と言ってもいくつかあって(again) MySQLサーバーの異常 MySQLサーバーからクライアントに返すネガティブな応答 クライアントライブラリーの異常 22/83
24. 「MySQLのエラー」と言ってもいくつかあって(again) MySQLサーバーの異常 プラグインやレプリケーションの “Initialization Failure” みたいな のはある ‐ それ以外はAssertion FailureだったりSegmentation Faultだったり でコア吐いたり、本物のデッドロックでストールしてたり ‐ MySQLサーバーからクライアントに返すネガティブな応答 概ね1000番台、5.7からたまに3000番台 ‐ クライアントライブラリーの異常 概ね2000番台（libmysqlclient.soの場合） ‐ クライアントライブラリーの実装に依存 ‐ 23/83
25. 最初につけられるアタリ クライアントサイドのエラー(2000番台)なら、そもそも サーバーに到達していない可能性がある 何らかの理由でサーバーが拒否ってるだけなら1000番台か3000番台 になるから ‐ ネットワーク経路的な問題が一番多い気がする ‐ クライアントサイドエラーでも、まれにサーバーがエラーに 絡んでいることもある クライアントライブラリーの互換性の問題 ‐ サーバー側からのコネクション強制切断 ‐ 24/83
26. 2002: CR_CONNECTION_ERROR ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2) 25/83
27. 2000番台エラーの特徴 サーバーから切られた以外の理由の場合、OSエラーコード が載っていることが多い 例えばLinuxなら #define ENOENT 2 /* No such file or directory */ #define ENOSPC 28 /* No space left on device */ #define ETIMEDOUT 110 /* Connection timed out */ #define ECONNREFUSED 111 /* Connection refused */ #define EHOSTUNREACH 113 /* No route to host */ 26/83
28. 2002: CR_CONNECTION_ERROR ERROR 2002 (HY000): Can't connect to local MySQL server through s ocket '/tmp/mysql.sock' (2) $ perror 2 OS error code 2: No such file or directory MySQL error code MY-000002: Error reading file '%s' (OS errno %d - %s) 27/83
29. 2000番台エラーの特徴 perror コマンドでは調べられ ない パッケージ的にサーバーの付属ユーティリティーだから、だと思う ‐ MySQL :: MySQL 8.0 Reference Manual :: 4.8.2 perror — Explain Error Codes ‐ OSエラーコードは perror コマンドで引ける ‐ OSエラーコードはたまにMySQLサーバーのエラーコードとカブるの で見失わないように… ‐ perror についてはあとで詳しく ‐ 28/83
30. 2003: CR_CONN_HOST_ERROR $ mysql -h10.0.0.1 ERROR 2003 (HY000): Can't connect to MySQL server on '10.0.0.1' (110) $ perror 2003 110 Illegal error code: 2003 OS error code 110: Connection timed out 29/83
31. 同じ2003のタイムアウトでもどっちがタイムアウトさせ るかによって違ったり mysql_options(mysql, MYSQL_OPT_READ_TIMEOUT, 1); mysql_real_connect(mysql); 2003: Can't connect to MySQL server on '192.168.225.201' (4) $ perror 4 OS error code 4: Interrupted system call 30/83
32. 2000番台でもサーバーの都合も含むもの サーバー側のアイドルタイマー（wait_timeout）に引っか かってサーバー側から一方的にコネクションを切断されたり KILLステートメントで切断されたり mysql80 11> SELECT NOW(); ERROR 2006 (HY000): MySQL server has gone away mysql80 13> SELECT NOW(); ERROR 2013 (HY000): Lost connection to MySQL server during query 31/83
33. どこで切断されるかでエラー番号が変わる mysql-client mysqld TCP Handshake Greeting Message/Mess age Digest User/Digest Authentication SELECT .. Execute query long_time SELECT .. Execute query 32/83
34. どこで切断されるかでエラー番号が変わる mysql80 11> SELECT NOW(); ERROR 2006 (HY000): MySQL server has gone away mysql80 13> SELECT NOW(); ERROR 2013 (HY000): Lost connection to MySQL server during query 33/83
35. 2000番台でもサーバーの都合も含むもの MySQL 8.0でみんなよくググるコレ ERROR 2059 (HY000): Authentication plugin 'caching_sha2_password' cannot be loaded: /usr/mysql/5.6.41/lib/plugin/caching_sha2_pass word.so: cannot open shared object file: No such file or director y 34/83
36. 2059: CR_AUTH_PLUGIN_CANNOT_LOAD クライアントが要求されたプラグインを見つけられないエ ラー。 MySQL 8.0のサーバーに5.6のクライアントで接続しようと すると出る 8.0のデフォルト認証プラグインは caching_sha2_password だが、こ れは5.6の時代には実装されていなかったため、クライアントはそん なプラグインを知らない。 ‐ 35/83
37. 実はもう1種類ある クライアントから送られてきたクライアントケーパビリ ティーで「要求する認証プラグインにクライアントが対応し ていないことがわかっちゃった」のでサーバーから接続を拒 否。 ERROR 1251 (08004): Client does not support authentication protoc ol requested by server; consider upgrading MySQL client 36/83
38. どこで認証に失敗するかでエラー番号が変わる mysql-client mysqld TCP Handshake Greeting Message/Mess age Digest User/Digest Authentication SELECT .. Execute query long_time SELECT .. Execute query 37/83
39. どこで認証に失敗するかでエラー番号が変わる ERROR 2059 (HY000): Authentication plugin 'caching_sha2_password' cannot be loaded: /usr/mysql/5.6.41/lib/plugin/caching_sha2_pass word.so: cannot open shared object file: No such file or director y ERROR 1251 (08004): Client does not support authentication protoc ol requested by server; consider upgrading MySQL client 38/83
40. libmysqlclient.so 製品名称は MySQL Connector/C MySQLサーバーにバンドルされている コイツをバインドしているのは PerlのDBD::mysql とか Rubyのmysql2とか PHPのmysqlnd, JavaのConnecor/J, PerlのNet::MySQL(!)とかは 独自実装 ‐ 39/83
41. 2000番台エラーの応用（？） レプリケーションスレーブ（のI/Oスレッド）はマスターか ら見ると クライアント しかも必ずlibmysqlclient.so実装のクライアント ‐ Last_IO_Error に2000番台のエラーが出ることがまれにだ がよくある ここで1000番台、2000番台の切り分けをスムーズにこなすとデキる MySQLerっぽい ‐ 40/83
42. Last_IO_ErrorはOSエラーコードが出てくれないのが ちょっと痛い 少なくとも認証失敗（1000番台）でないことはわかる Last_IO_Errno: 2003 Last_IO_Error: error connecting to master 'root@1 27.0.0.1:64057' - retry-time: 60 retries: 1 クライアントサイドエラーコードの一覧は include/ errmsg.h に 41/83
43. おまけ: Connector/J “Communication link failure” って邪悪なやつがいて src/com/mysql/jdbc/ConnectionImpl.java ‐ src/com/mysql/jdbc/ConnectionImpl.java ‐ 更にすごいことには src/com/mysql/jdbc/SQLError.java ‐ 42/83
44. ひどい XD 個人の意見です 43/83
45. エラーコード分類 range error_kbn 1..999 グローバルエラー 1000..1999 サーバーサイドエラー 2000..2999 クライアントサイドエラー (*) 3000..4999 サーバーサイドエラー 5000..5999 X Pluginのエラー 10000..49999 システムメッセージ 50000..51999 サードパーティ用 (*) libmysqlclient.soの場合 MySQL :: MySQL 8.0 Reference Manual :: B.1 Error Message Sources and Components 44/83
46. 次ににつけられるアタリ 1000番台、3000番台ならサーバーが明示的に「エラー応答」を 返している ERRパケットの中には「サーバーサイドエラーコード」「SQLス テート」「エラーメッセージ」が入っている 45/83
47. たとえば エラーコード1251 SQLステート08004 エラーメッセージが “Client does not ..” ERROR 1251 (08004): Client does not support authentication protoc ol requested by server; consider upgrading MySQL client 46/83
48. SQLステート サーバーサイドエラーコードとSQLステートは1対多で結び つく なので、積極的にSQLステートを使うクライアントでなければエラー コードの方が追いやすい ‐ Wikipediaさん後は頼んだ SQLSTATE - Wikipedia ‐ 47/83
49. エラーメッセージ 豆だけど実は日本語にできる lc_messages=ja ‐ MySQL :: MySQL 5.6 リファレンスマニュアル :: 10.2 エラーメッ セージ言語の設定 ‐ 48/83
50. 誰得 mysql80 32> SELECT 1 FROM t1; ERROR 1046 (3D000): No database selected mysql80 32> SET lc_messages= 'ja_JP'; Query OK, 0 rows affected (0.01 sec) mysql80 32> SELECT 1 FROM t1; ERROR 1046 (3D000): データベースが選択されていません。 share/errmsg-utf8.txt から “jpn” で始まってる行を探すと 出てきます 最近増えたエラーコードは網羅されていないのでコントリビュート チャンスですね :D ‐ 49/83
51. perrorコマンド $ perror 1046 MySQL error code MY-001046 (ER_NO_DB_ERROR): No database selected $ perror ER_NO_DB_ERROR MySQL error code MY-001046 (ER_NO_DB_ERROR): No database selected 50/83
52. perrorコマンド さっきから何度か出てきている perror コマンド パッケージ的には mysql-server 系に付属している 引数にエラーコードを受けて、エラーメッセージのフォー マットを出力する エラー番号からだけでもエラーメッセージを推測できる ‐ エラー番号からマクロ名が取り出せるのでgrepが捗る ‐ マクロ名しか書いてない（ことはまずないと思うけど）からエラー番 号とメッセージが取れる ‐ MySQL :: MySQL 5.6 リファレンスマニュアル :: 4.8.1 perror — エラーコードの説明 51/83
53. perrorコマンド 内部理解のために役に立つのは、 どこまでが決め打ちメッ セージなのか がわかるフォーマットを見られること たとえば 1593: ER_BINLOG_FATAL_ERROR は(5.7の場 合) Slave I/O: The slave I/O thread stops because master and slave ha ve equal MySQL server ids; these ids must be different for replic ation to work (or the --replicate-same-server-id option must be u sed on slave but this does not always make sense; please check th e manual before using it), Error_code: 1593 Slave I/O: The slave I/O thread stops because SET @master_heartbe at_period on master failed. Error: , Error_code: 1593 Slave SQL: Fatal error: Failed to initialize the master info stru cture, Error_code: 1593 52/83
54. 1593: ER_BINLOG_FATAL_ERROR perrorで引くとほとんどが可変部分で、このエラーコードが 示すものは “Fatal error” しかない（あとは全部状況で変わ る） $ perror 1593 MySQL error code 1593 (ER_SLAVE_FATAL_ERROR): Fatal error: %s 53/83
55. じゃあどこでこのバリエーションが生まれるのか？ エラーマクロが分かってればgrepは簡単 $ grep -r -A1 ER_SLAVE_FATAL_ERROR . ... ./sql/log_event.cc: rli->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ./sql/log_event.cc: ER_THD(thd, ER_SLAVE_FATAL_ERROR), ./sql/log_event.cc- "Invalid character set for User var event"); -- ./sql/rpl_slave.cc: mi->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ./sql/rpl_slave.cc: ER(ER_SLAVE_FATAL_ERROR), ./sql/rpl_slave.cc- "Failed to flush master info."); -- ./sql/log_event.cc: rli->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ./sql/log_event.cc: ER_THD(thd, ER_SLAVE_FATAL_ERROR), ./sql/log_event.cc- "Binlog version not supported"); ... 54/83
56. 慣れてくると mi は master_info のことでI/Oスレッド関連 rli は relay_log_info のことでSQLスレッド関連 それぞれ report は SHOW SLAVE STATUS で表示されるような バッファ（とエラーログ）に記録するためのメソッド 55/83
57. 慣れてくると $ grep -r -A1 ER_SLAVE_FATAL_ERROR . ... ./sql/log_event.cc: rli->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ./sql/log_event.cc: ER_THD(thd, ER_SLAVE_FATAL_ERROR), ./sql/log_event.cc- "Invalid character set for User var event"); -- ./sql/rpl_slave.cc: mi->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ./sql/rpl_slave.cc: ER(ER_SLAVE_FATAL_ERROR), ./sql/rpl_slave.cc- "Failed to flush master info."); -- ./sql/log_event.cc: rli->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ./sql/log_event.cc: ER_THD(thd, ER_SLAVE_FATAL_ERROR), ./sql/log_event.cc- "Binlog version not supported"); ... 56/83
58. C怖くないよ 2506 char query_buf[]= "SELECT @@GLOBAL.SERVER_UUID"; .. 2535 if (!mysql_real_query(mysql, STRING_WITH_LEN(query_buf)) && 2536 (master_res= mysql_store_result(mysql)) && 2537 (master_row= mysql_fetch_row(master_res))) 2538 { 2539 if (!strcmp(::server_uuid, master_row[0]) && 2540 !mi->rli->replicate_same_server_id) 2541 { 2542 errmsg= "The slave I/O thread stops because master and slave have equal " 2543 "MySQL server UUIDs; these UUIDs must be different for " 2544 "replication to work."; 2545 mi->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ER(ER_SLAVE_FATAL_ERROR), 2546 errmsg); 2547 // Fatal error 2548 ret= 1; 2549 } sql/rpl_slave.cc 57/83
59. $ がない以外 はほぼPerl :D 58/83
60. エラーフォーマットからエラーの意味を察する 可変部分は呼び出し元から文字列で渡されるので、1593な ら “Fatal error:” の他の部分はソースコードから探しやすい それに対して1046は可変部分がないのでエラーマクロで探 すしかない $ perror 1046 MySQL error code 1046 (ER_NO_DB_ERROR): No database selected $ perror 1593 MySQL error code 1593 (ER_SLAVE_FATAL_ERROR): Fatal error: %s 59/83
61. エラーフォーマットからエラーの意味を察する これは grep -r "UUIDs must be different" . でもたどり着 ける 2506 char query_buf[]= "SELECT @@GLOBAL.SERVER_UUID"; .. 2535 if (!mysql_real_query(mysql, STRING_WITH_LEN(query_buf)) && 2536 (master_res= mysql_store_result(mysql)) && 2537 (master_row= mysql_fetch_row(master_res))) 2538 { 2539 if (!strcmp(::server_uuid, master_row[0]) && 2540 !mi->rli->replicate_same_server_id) 2541 { 2542 errmsg= "The slave I/O thread stops because master and slave have equal " 2543 "MySQL server UUIDs; these UUIDs must be different for " 2544 "replication to work."; 2545 mi->report(ERROR_LEVEL, ER_SLAVE_FATAL_ERROR, ER(ER_SLAVE_FATAL_ERROR), 2546 errmsg); 2547 // Fatal error 2548 ret= 1; 2549 } sql/rpl_slave.cc 60/83
62. エラーフォーマットからエラーの意味を察する grep -r "No database selected" . だとテストケースとマ クロの定義部分しか出てこない それはそれで楽しいんですけどね :D ‐ ... ./include/mysqld_ername.h:{ "ER_NO_DB_ERROR", 1046, "No database selected" }, ./mysql-test/r/alter_table.result:ERROR 3D000: No database select ed ./mysql-test/r/create.result:ERROR 3D000: No database selected ./mysql-test/t/information_schema.test:# Bug#38916 Select from I_ S.ROUTINES results in "No database selected" error ./mysql-test/t/sp.test:# Bug#28551 "The warning 'No database sele cted' is reported when calling ... 61/83
63. エラーに触れるつい でにエラーログにつ いても触れておこう 62/83
64. MySQLのエラーログとは実は open_error_log でやっていることの実態は、 freopen を 使ってstderrとstdoutをエラーログに向けているだけ 1894 bool open_error_log(const char *filename, bool get_lock) { ... 1915 do { 1916 errors = 0; 1917 if (!my_freopen(filename, "a", stderr)) errors++; 1918 if (!my_freopen(filename, "a", stdout)) errors++; 1919 } while (retries-- && errors); 1920 sql/log.cc 63/83
65. lsofで開いているファイルディスクリプターを見るだけで もわかったりする $ lsof -p $(pidof mysqld) .. mysqld 20980 yoku0825 0r CHR 1,3 0t0 1028 /dev/null mysqld 20980 yoku0825 1w REG 253,0 52083 137048897 /usr/mysql/8.0.14/data/error.log mysqld 20980 yoku0825 2w REG 253,0 52083 137048897 /usr/mysql/8.0.14/data/error.log mysqld 20980 yoku0825 3u REG 253,0 65 149633590 /usr/mysql/8.0.14/data/bin.index mysqld 20980 yoku0825 4u REG 253,0 4077 149596931 /usr/mysql/8.0.14/data/innodb_status.20980 .. 64/83
66. stdoutとstderrが繋がっているだけなので プラグインの中で fprintf(stderr, ..) とかやるとフツーに エラーログに出る printデバッグする機会があれば憶えておいて損はないはず ;) ‐ InnoDB Monitor( CREATE TABLE innodb_monitor とか SET GLOBAL innodb_status_output = 1 )がなんでデフォルトで エラーログに書かれるのか… InnoDBからするとエラーログに書いてるつもりはなくて、単に標準 エラー出力に書いているだけ ‐ ロガープロセスみたいなのがいるわけではない 65/83
67. stdoutとstderrが繋がっているだけなので おもむろにエラーログの書式をガン無視したInnoDBのログ に遭遇したことってありません？ タイムスタンプとかログレベルとか一切ないやつ ‐ 180731 13:29:08 [Note] InnoDB: 5.5.61 started; log sequence numbe r 1625977 InnoDB: Error: page 1234 log sequence number InnoDB: is in the future! Current system log sequence number 1625 977 InnoDB: Your database may be corrupt or you may have copied the I nnoDB InnoDB: tablespace but not the InnoDB log files. See" InnoDB: https://dev.mysql.com/../forcing-innodb-recovery.html InnoDB: for more information. 66/83
68. stdoutとstderrが繋がっているだけなので 8.0はもうかなり ib::error をちゃんと使うように書き換え られているけれども 3925 ib::error(ER_IB_MSG_37) << "Has " << rec_get_n_fields_ol d(rec, index) 3926 << " fields, should have " << n; 3927 3928 if (dump_on_error) { 3929 fputs("InnoDB: corrupt record ", stderr); 3930 rec_print_old(stderr, rec); 3931 putc('\n', stderr); 3932 } 3933 return (FALSE); storage/innobase/btr/btr0btr.cc 67/83
69. プラガブルストレージエンジン 今でこそMySQLのストレージエンジンといえばInnoDBだけ れども かつてMySQLは “MySQL AB.” が InnoDBは “Innobase Oy.” (後にOracleが買収) が それぞれ別々に開発していた 68/83
70. InnoDBの余談 別の会社によって、別のリポジトリーで、別の製品として開 発されたInnoDB バージョン体系も違っていて、5.1時代のInnoDB PluginはInnoDB 1.0.x ‐ MySQL 5.5のInnoDBはInnoDB 1.1.x ‐ OracleによるSun買収直後のリリースがMySQL 5.5だか ら、Oracleになってから開発されたバージョンはMySQL 5.6から 5.6からはInnoDBにバージョン番号は振られていない ‐ 69/83
71. 閑話休題 70/83
72. プラガブルストレージエンジンのログ 別のファイルに吐く 1. Mroongaストレージエンジン（ groonga.log ） ISAMストレージエンジン (デバッグ用の log_isam オプショ ンはなんと8.0にもまだある) 標準エラー出力に吐く 1. InnoDBストレージエンジン NDBCLUSTERストレージエンジン（データノードは独自ロ グ） 71/83
73. mysqldのエラーロギングも進化している MySQL 8.0でサーバーコアのコードはなんちゃってC++か らほぼネイティブなC++に ちゃんとしたメッセージフックが実装された ‐ MySQL 8.0からはエラーログフィルターとJSONコンポーネ ントが追加できる mysql80 10> SELECT @@log_error_services; +-------------------------------------------------------+ | @@log_error_services | +-------------------------------------------------------+ | log_filter_internal; log_sink_internal; log_sink_json | +-------------------------------------------------------+ 1 row in set (0.00 sec) 72/83
74. JSON形式のエラーログ { "log_type": 1, "prio": 0, "err_code": 10931, "msg": "/usr/mysql/8.0.14/bin/mysqld: ready for connections. Ve rsion: '8.0.14' socket: '/usr/mysql/8.0.14/data/mysql.sock' por t: 64080 Source distribution.", "time": "2019-01-25T14:15:23.491017Z", "err_symbol": "ER_SERVER_STARTUP_MSG", "SQL_state": "HY000", "subsystem": "Server", "label": "System" } 73/83
75. エラーログで ついでに思い 出した 74/83
76. 有名なアレ mysqld got signal 11; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware. We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail. key_buffer_size=67108864 read_buffer_size=2093056 max_used_connections=0 max_connections=3000 threads_connected=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 30773 512 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. 75/83
77. 実はこのメッセージはハードコード 115 my_safe_printf_stderr("%s", 116 "This could be because you hit a bug. It is also " 117 "possible that this binary\n" 118 "or one of the libraries it was linke d against is " 119 "corrupt, improperly built,\n" 120 "or misconfigured. This error can als o be caused by " 121 "malfunctioning hardware.\n"); sql/signal_handler.cc 76/83
78. 未だに key_buffer_size がどうこう言うのも 単にハードコードされてるのを直してないだけ innodb_buffer_pool_size が出てこないのも単に直してないだけ ‐ 130 my_safe_printf_stderr("key_buffer_size=%lu\n", 131 (ulong)dflt_key_cache->key_cache_mem_ size); sql/signal_handler.cc 77/83
79. handle_fatal_signal に対する雑な所感 signal 11(SIGSEGV)だと本物の（？）バグっぽさが上がる signal 6(SIGABRT)はAssertionに引っかかってるケース 多くの場合、InnoDBのページ破損とかになるんじゃなかろうか ‐ この場合はバグじゃないからあの固定メッセージ出さなくて良い気 が… ‐ handle_fatal_signal が何も言わない時はsignal 9なので OOM Killerさんの可能性が非常に高い 78/83
80. あと、何かの名残 5.1, 5.5, 5.6にはこんな分岐があった 未実装のまま5.7からは消えてる ‐ 1160 switch (error_log_printer) { 1161 case LOG_FILE: 1162 error_log_handler_list[0]= file_log_handler; 1163 error_log_handler_list[1]= 0; 1164 break; 1165 /* these two are disabled for now */ 1166 case LOG_TABLE: 1167 DBUG_ASSERT(0); 1168 break; 1169 case LOG_TABLE|LOG_FILE: 1170 DBUG_ASSERT(0); 1171 break; 1172 } sql/log.cc 79/83
81. それを言い出すとmysqld_safeのエラーログ これもシェルスクリプトの中で各コマンドの標準出力と標準 エラー出力をリダイレクトでファイルに向けているだけ mysqldのログがsyslogに吐けるようになったのは最近だけ どmysqld_safeのログが昔っから吐けたのは単にloggerコマ ンドを使えば良かったから mysqldの方はログを書き込む関数を呼ばずにあちこちまちまちに書 いてたのでそれを統合するところから始まったんだと思う ‐ そんなのもあってログ用の関数はメジャーバージョンのたびにガリガ リ書き換わってるので、ストレージエンジンとかで真面目にそこを呼 んでいるお行儀の良いやつはマクロで大変な気がする ‐ 80/83
82. おっと何 の話だ 81/83
83. まとめ エラーにはクライアントサイドエラーとサーバーサイドエ ラーがある サーバーサイドエラーはものによって汎用的すぎるエラーが あったり、特化しすぎたエラーがあったりでグレッパビリ ティーが変わる エラーログ駆動でソースコードを読むのは楽しい See also, エラーログドリブン ソースコードリーディング(ただし MySQLに限る) | GMOメディア エンジニアブログ ‐ 82/83
84. Any Questions and/or Suggestions? 83/83