故障分析|グローバルリードロックはずっと解放されていません.何が起こりましたか?


作者:劉開洋
愛可生交付サービス部チーム北京DBAは、主にMySQLのtroubleshootingと我が社の自研データベース自動化管理プラットフォームDMPの日常運営と維持問題を処理し、データベースと周辺技術に対して濃厚な学習興味を持ち、本を読むことが好きで、技術を追求している.
オリジナル投稿
*爱可生开源社区出品,原创内容无许可使用,转载请联系小编,并注明出所.
質問:
お客様のオンライン監視アラームでは、プロンプトの主が遅延から上昇し続けています.データベースに登って見てみると、MySQLがライブラリからコピーされたステータスプロンプトSQLスレッドがwaiting for global read lockにあることがわかります.
データベースのプロセスリストに、グローバルリードロックとkill slaveを待つプロセスが存在することが分かった.NATネットワークでドメイン名の逆解析エラーが発生したため、高可用性ソフトウェアによるレプリケーションの誤審のため、レプリケーションを継続的に再起動できます.
ここで2つの問題がわかります.1つ目は、グローバル・リード・ロックを送信するオブジェクトであり、一般的にはライブラリからバックアップ・ツールであり、2つ目はslaveがkillされており、時間がかなり長いため、特殊なデッドロックが存在する可能性があります.
mysqlプロセスを表示したときの偶然の一致で、mysqldumpプロセスはすでに10時間以上存在していることがわかりました.FTWRLのプロセスを待つ時間と比較して、下発グローバルリードロックの対象はmysqldumpです.
オンラインでperformanceが開いていません.schemaのinstrumentsとconsumers(PS:これはロックモニタリングにとって重要で、必ず開くことを覚えています).performanceを開いたらschema、metadataでlocksは関連ロックの記録を調べました.これは後の再現で見てみましょう.
上記の状況分析から、MySQL Server層とストレージエンジン層のデッドロック閉ループを形成し、すべてのロック記録を完全に追跡できない特殊なデッドロックが存在することが分かった.
解決:
このように3つのロックグループが合成したデッドロックは他のクライアントでUNLOCKS TABLEを実行することは解けない.killがグローバルリードロックを落とすか、グローバルロックのロックを待つだけでいい.グローバルロックに対応するスレッドが見つからないため、ここではグローバルロックのスレッドkillが落ちるのを待って、データベースが回復し、残りのmysqldumpプロセスが消えた.
2つの鍵が解けた
フェイルオーバ・リカバリ.
Revew:stop slaveとFTWRLでデッドロックが発生したのはなぜですか?
mysql 5.7.26でmysqldumpプラスパラメータmaster_を実行data、single_Transactionとflush_logsで得られたgeneral logで発見された
mysqldump   general log
[email protected] on  using TCP/IP
/*!40100 SET @@SQL_MODE='' */
/*!40103 SET TIME_ZONE='+00:00' */
FLUSH /*!40101 LOCAL */ TABLES
FLUSH TABLES WITH READ LOCK                                       #      
Refresh                                                           #     
  
SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ           #         RR
START TRANSACTION /*!40100 WITH CONSISTENT SNAPSHOT */          
SHOW MASTER STATUS                                                #   master   
UNLOCK TABLES                                                     #    
···
Quit

シーンの再現:
[root@localhost ~]# gdb -ex "set pagination 0" -ex "thread apply all bt" --batch -p 13192   #     MySQL    ——  stop slave          
······
Thread 23 (Thread 0x7f98f027e700 (LWP 19446)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 ()
#1  native_cond_timedwait
#2  my_cond_timedwait
#3  inline_mysql_cond_timedwait
#4  terminate_slave_thread (thd=0x7f98740008c0, term_lock=0x7f9884022908, term_cond=0x7f9884022a08, slave_running=0x7f9884022ac4, stop_wait_timeout=0x7f98f027c448, need_lock_term=false) at /export/home/pb2/build/sb_0-33648028-1555164244.06/mysql-5.7.26/sql/rpl_slave.cc:1861
#5  terminate_slave_threads (mi=0x7f988401c500, thread_mask=3, stop_wait_timeout=, need_lock_term=false) at /export/home/pb2/build/sb_0-33648028-1555164244.06/mysql-5.7.26/sql/rpl_slave.cc:1671
#6  stop_slave (thd=0x7f987c00f650, mi=0x7f988401c500, net_report=true, for_one_channel=false, push_temp_tables_warning=0x7f98f027c52f) at /export/home/pb2/build/sb_0-33648028-1555164244.06/mysql-5.7.26/sql/rpl_slave.cc:10261
#7  stop_slave (thd=0x7f987c00f650) at /export/home/pb2/build/sb_0-33648028-1555164244.06/mysql-5.7.26/sql/rpl_slave.cc:615
#8  stop_slave_cmd
#9  mysql_execute_command
#10 mysql_parse
#11 dispatch_command
#12 do_command
#13 handle_connection
#14 pfs_spawn_thread
#15 start_thread ()
#16n clone ()
  
#     # 5 stop_wait_timeout,        
(gdb) thread 34
[Switching to thread 34 (Thread 0x7f58d661f700 (LWP 13240))]
#0  0x00007f592d8e0d42 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
(gdb) f 5
#5  0x0000000000f0ed57 in terminate_slave_threads (mi=0x7f587801f050, thread_mask=3, stop_wait_timeout=, need_lock_term=false)
    at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.26/sql/rpl_slave.cc:1671
warning: Source file is more recent than executable.
1671        if ((error=terminate_slave_thread(mi->rli->info_thd, sql_lock,
(gdb) print mi->rli->info_thd
$1 = (THD *) 0x7f58700008c0
 
  
Thread 21 (Thread 0x7f58c05a6700 (LWP 14238)):
#9  apply_event_and_update_pos (ptr_ev=0x7f58c05a56c8, thd=0x7f58700008c0, rli=0x7f5878024b30)
#10 exec_relay_log_event (thd=0x7f58700008c0, rli=0x7f5878024b30)
  
#   gdb    stop slave  mi->rli->info_thd,          0x7f58700008c0,     21 apply_event_and_update_pos  exec_relay_log_event    
apply_event_and_update_pos:         relay log   。
exec_relay_log_event:   SQL       relay log           。
mi=master info, rli=relay log info

terminate_slave_thread関数:SQL threadの終了を待つ関数.この関数は、要求スレッドの終了後に呼び出され(Relay_log_infoまたはMaster_info構成のabort_slaveを1に設定することにより)、スレッドの終了は*slave_running制御.関数は、待機条件の前にterm_を取得します.lock,need_lock_termがfalseの場合、mutexはこの関数の呼び出し者に属するべきであり、関数が返された後もmutexを取得した状態を維持する.
mysqldumpバックアップ中に発生するアクションは、次のとおりです.
  • master-data=2はsingle-transactionと組み合わせてデータベースにグローバルリードロックを追加します.
  • flush-logsはrelay logに対してrefreshを行う.

  • STOP SLAVEのバックアップ中の操作は次のとおりです.
  • STOP SLAVEはIOスレッドの終了を待ってLOCK_を解放しますmsp_mapと占有master_info

  • プロセス:
  • mysqldumpバックアップFTWRLを行った後、HAがSTOP SLAVEを実行するのに偶然出会った.SQL ThreadはSTOPの前にmi->stop_を持っているcondロック、commitの時はMDLを待ちますCOMMIT,FTWRLの後に実行されたflush logs時にrefreshはmi->stop_を待つシステムロックを発行した.condの解放は、FTWRLとFLUSH LOGSがプログラムで発行されたため、論理的にはmysqldump自身がリソースの解放を待っているため、無限の待機に陥り、私たちが見たデッドロックを形成した.

  • LOCK_についてmsp_mapロックの興味のある学生は自分でグーグルで検索することができます
    参照先:
    https://bugs.mysql.com/bug.ph...
    https://bugs.mysql.com/file.p...
    https://www.percona.com/blog/...