什麼？MySQL 8.0 會同時修改兩個ib_logfilesN 文件？

来源:https://www.cnblogs.com/greatsql/archive/2022/09/05/16656852.html
-Advertisement-
Play Games

GreatSQL社區原創內容未經授權不得隨意使用，轉載請聯繫小編並註明來源。 GreatSQL是MySQL的國產分支版本，使用上與MySQL一致。 作者介紹：孫黎，GreatDB 認證DBA 問題現象描述 測試MySQL單機時，無意發現，MySQL 8.0的 ib_logfilesN的顯示如下： l ...


  • GreatSQL社區原創內容未經授權不得隨意使用，轉載請聯繫小編並註明來源。
  • GreatSQL是MySQL的國產分支版本，使用上與MySQL一致。
  • 作者介紹：孫黎，GreatDB 認證DBA

問題現象描述

測試MySQL單機時，無意發現，MySQL 8.0的 ib_logfilesN的顯示如下：

ll ib_logfile*
-rw-r----- 1 greatsql greatsql 134217728 8月 4 18:36 ib_logfile0
-rw-r----- 1 greatsql greatsql 134217728 7月 27 17:31 ib_logfile1
-rw-r----- 1 greatsql greatsql 134217728 8月 4 18:03 ib_logfile2
-rw-r----- 1 greatsql greatsql 134217728 8月 4 18:36 ib_logfile3

其中ib_logfile0、iblogfile3的 最近改動時間為：2022-08-04 18:36

印象中，MySQL 8.0對 redo 做了大量優化，難道刷盤也做了改變？

重現現象

趕緊登錄到MySQL 重新執行一條insert，再觀察一下。

1  ib_logfile*
2 -rw-r----- 1 greatsql greatsql 134217728 8月   9 22:55 ib_logfile0
3 -rw-r----- 1 greatsql greatsql 134217728 7月  27 17:31 ib_logfile1
4 -rw-r----- 1 greatsql greatsql 134217728 8月   4 18:03 ib_logfile2
5 -rw-r----- 1 greatsql greatsql 134217728 8月   9 22:55 ib_logfile3
6 [#3#root@greatsql82 /data/mysql8023/data 22:55:45]3 stat  ib_logfile0
7 文件："ib_logfile0"`
8 大小：134217728       塊：262144     IO 塊：4096   普通文件
9 設備：fd00h/64768d      Inode：75740704    硬鏈接：1
10 許可權：(0640/-rw-r-----)  Uid：( 1000/ greatsql)   Gid：( 1000/ greatsql)
11 最近訪問：2022-08-04 19:22:32.746184752 +0800
12 最近更改：2022-08-09 22:55:40.166964294 +0800
13 最近改動：2022-08-09 22:55:40.166964294 +0800
14 創建時間：-`
15 [#4#root@greatsql82 /data/mysql8023/data 22:56:13]4 stat  ib_logfile3
16 文件："ib_logfile3"
17 大小：134217728       塊：262144     IO 塊：4096   普通文件
18 設備：*******       Inode：75740707    硬鏈接：1
19 許可權：(0640/-rw-r-----)  Uid：( 1000/ greatsql)   Gid：( 1000/ greatsql)
20 最近訪問：2022-08-04 19:22:48.510210526 +0800
21 最近更改：2022-08-09 22:55:39.741963331 +0800
22 最近改動：2022-08-09 22:55:39.741963331 +0800
23 創建時間：-

在MySQL端執行一個事務後，可以看到ib_logfile0、iblogfile3都發生了改變，iblogfile3先改變，iblogfile0後改變，且改動時間相差不到0.42s

趕緊翻一下官網手冊

By default, the redo log is physically represented on disk by two files named ib_logfile0 and ib_logfile1. MySQL writes to the redo log files in a circular fashion.

沒有新變化，依舊是迴圈寫
（那為啥寫了iblogfile3後，還會寫iblogfile0呢？）

實踐追蹤

最直接的當然是去看源碼，一切盡在源碼中。不過看代碼實在太麻煩，不太適合大多數的人，gdb debug 過程，技術要求門檻較高。

有沒有一個工具，能讓運維人員直觀地觀測一下呢?

當然有！

sysdig這是筆者在GreatSQL社區瞭解到的一款觀測性神器。

在MySQL執行

insert into test.t values(1,'aa');

追蹤如下：

1 sysdig    proc.pid=2617   and  fd.type=file  
2    273983 01:02:18.534336211 1 mysqld (2617.3021) < open fd=39(<f>/data/mysql8023/data/test/t.ibd) name=./test/t.ibd(/data/mysql8023/data/test/t.ibd) flags=1(O_RDONLY) mode=0 dev=FD00
3    `273988 01:02:18.534381910 1 mysqld (2617.3021) > lseek fd=39(<f>/data/mysql8023/data/test/t.ibd) offset=0 whence=1(SEEK_CUR)
4    `273989 01:02:18.534384266 1 mysqld (2617.3021) < lseek res=0
5    `273990 01:02:18.534385778 1 mysqld (2617.3021) > lseek fd=39(<f>/data/mysql8023/data/test/t.ibd) offset=0 whence=2(SEEK_END)
6    `273991 01:02:18.534386657 1 mysqld (2617.3021) < lseek res=114688
7    `273992 01:02:18.534387686 1 mysqld (2617.3021) > lseek fd=39(<f>/data/mysql8023/data/test/t.ibd) offset=0 whence=0(SEEK_SET)
8    `273993 01:02:18.534388675 1 mysqld (2617.3021) < lseek res=0
9    273996 01:02:18.534428831 1 mysqld (2617.3021) > pread fd=39(<f>/data/mysql8023/data/test/t.ibd) size=1024 pos=0
10    273997 01:02:18.534446476 1 mysqld (2617.3021) < pread res=1024 data=:.........8..........eKq.............................@..@!......................
11    273998 01:02:18.534449603 1 mysqld (2617.3021) > pread fd=39(<f>/data/mysql8023/data/test/t.ibd) size=16384 pos=0
12    273999 01:02:18.534481272 1 mysqld (2617.3021) < pread res=16384 data=:.........8..........eKq.............................@..@!......................
13    274000 01:02:18.534485006 1 mysqld (2617.3021) > close fd=39(<f>/data/mysql8023/data/test/t.ibd)
14    274001 01:02:18.534487333 1 mysqld (2617.3021) < close res=0
15    274003 01:02:18.534504990 1 mysqld (2617.3021) < open fd=39(<f>/data/mysql8023/data/test/t.ibd) name=./test/t.ibd(/data/mysql8023/data/test/t.ibd) flags=3(O_RDWR) mode=0 dev=FD00
16    274004 01:02:18.534507922 1 mysqld (2617.3021) > fcntl fd=39(<f>/data/mysql8023/data/test/t.ibd) cmd=5(F_SETFL)
17    274005 01:02:18.534510349 1 mysqld (2617.3021) < fcntl res=0(<f>/dev/null)
18    274006 01:02:18.534511842 1 mysqld (2617.3021) > fcntl fd=39(<f>/data/mysql8023/data/test/t.ibd) cmd=8(F_SETLK)
19    274007 01:02:18.534518620 1 mysqld (2617.3021) < fcntl res=0(<f>/dev/null)
20    274012 01:02:18.534537370 1 mysqld (2617.3021) > pread fd=39(<f>/data/mysql8023/data/test/t.ibd) size=16384 pos=65536
21    274549 01:02:18.551004551 2 mysqld (2617.3021) < pread res=16384 data=x...................?..KE................x......................................
22    274553 01:02:18.551086413 2 mysqld (2617.3021) > pread fd=39(<f>/data/mysql8023/data/test/t.ibd) size=16384 pos=16384
23    274578 01:02:18.553158586 2 mysqld (2617.3021) < pread res=16384 data=..Nv.................e>8........................................................
24    274904 01:02:18.567111657 3 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=1024 pos=133301760
25    274908 01:02:18.567152231 3 mysqld (2617.2665) < pwrite res=1024 data=.......N.."......Z/........Q.......Q.......:......Z/r.........Z/...........*....
26    274912 01:02:18.567167495 3 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=512 pos=133302784
27    274913 01:02:18.567170922 3 mysqld (2617.2665) < pwrite res=512 data=.....x.x..".....................................................................
28    275149 01:02:18.573320262 2 mysqld (2617.3021) > write fd=36(<f>/data/mysql8023/log/mysql-bin.000011) size=275
29    275150 01:02:18.573353921 2 mysqld (2617.3021) < write res=275 data=...b!....K.............'.5...Q..'w{...........................9 ........8.....b.
30    275244 01:02:18.574223831 3 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=512 pos=133302784
31    275245 01:02:18.574249340 3 mysqld (2617.2665) < pwrite res=512 data=.....p.x..".....................................................................
32    276355 01:02:18.652355052 1 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=512 pos=133302784
33    276362 01:02:18.652389109 1 mysqld (2617.2665) < pwrite res=512 data=.......x..".....................................................................
34    276366 01:02:18.652400127 1 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=512 pos=133303296
35    276369 01:02:18.652404698 1 mysqld (2617.2665) < pwrite res=512 data=..........".......8.............................................................
36    277222 01:02:18.658160528 1 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=512 pos=133303296
37    277223 01:02:18.658196012 1 mysqld (2617.2665) < pwrite res=512 data=..........".......8....>$.......................................................
38    279425 01:02:18.769808947 1 mysqld (2617.2665) > pwrite fd=11(<f>/data/mysql8023/data/ib_logfile3) size=512 pos=133303296` 
39    279426 01:02:18.769861708 1 mysqld (2617.2665) < pwrite res=512 data=.....(....".......8....>$........>$.............................................
40    281529 01:02:18.924391804 3 mysqld (2617.2657) > pwrite fd=12(<f>/data/mysql8023/data/#ib_16384_0.dblwr) size=147456 pos=262144` 
41    281539 01:02:18.925125943 3 mysqld (2617.2657) < pwrite res=147456 data=.E..................?..(........................................................
42    302247 01:02:19.924998103 0 mysqld (2617.2661) > pwrite fd=4(<f>/data/mysql8023/data/ib_logfile0) size=512 pos=512` 
43    302248 01:02:19.925043052 0 mysqld (2617.2661) < pwrite res=512 data=......".....?..(.......(........................................................

分析過程

分析以上追蹤日誌，可以得到：

1、
（2617.3021） 2617 是 mysqld 進程號， 3021 是執行sql語句的THREAD_OS_ID，可以看到操作t.ibd文件（FD39)的完整過程，這裡沒有追蹤到FD39 write的過程，說明redo日誌落盤，checkpoint向前更新，就能完成事務提交，不需要等待數據的真正落盤。

2、

  • 2665線程 thread/innodb/log_writer_thread 先寫/data/mysql8023/data/ib_logfile3

  • 2661線程thread/innodb/log_checkpointer_thread 更新/data/mysql8023/data/ib_logfile0 pos512 和 pos1536 兩個位置

 select  *  from  threads  where  THREAD_OS_ID  in (2665,2661) \G
    *************************** 1. row ***************************
              THREAD_ID: 27
                   NAME: thread/innodb/log_checkpointer_thread
                   TYPE: BACKGROUND
    
    ...
    
            THREAD_OS_ID: 2661
                RESOURCE_GROUP: SYS_default
    *************************** 2. row ***************************
              THREAD_ID: 31
                   NAME: thread/innodb/log_writer_thread
                   TYPE: BACKGROUND
    ...
                 THREAD_OS_ID: 2665
              RESOURCE_GROUP: SYS_default
    2 rows in set (0.00 sec)

3、log_filesN每次更新的大小為512B *N N>=1

4、 當前正在記錄redo內容的文件為ib_logfile3 pos到了133303296

以上通過可觀測性追蹤，粗略驗證了 前文對 "Ib_logfile的checkpoint field"的描述準確性。

理論依據

事務日誌或稱redo日誌，在MySQL中預設以ib_logfile0,ib_logfile1名稱存在,可以手工修改參數，調節開啟幾組日誌來服務於當前MySQL資料庫,MySQL採用順序，迴圈寫方式，每開啟一個事務時，會把一些相關信息記錄事務日誌中(記錄對數據文件數據修改的物理位置或叫做偏移量);

這個系列文件個數由參數innodb_log_files_in_group控制，若設置為4，則命名為ib_logfile0~3

這些文件的寫入是順序、迴圈寫的，logfile0寫完從logfile1繼續，logfile3寫完則logfile0繼續。

在系統崩潰重啟時，作事務重做；在系統正常時，每次checkpoint時間點，會將之前寫入事務應用到數據文件中。

Ib_logfile的checkpoint field

實際上不僅要記錄checkpoint做到哪兒(LOG_CHECKPOINT_LSN)，還要記錄用到了哪個位置(LOG_CHECKPOINT_OFFSET)等其他信息。所以在ib_logfile0的頭部預留了空間，用於記錄這些信息。

因此即使使用後面的logfile，每次checkpoint完成後，ib_logfile0都是要更新的。同時你會發現所謂的順序寫盤，也並不是絕對的

相關的一些數字

a) InnoDB留了兩個checkpoint filed，按照註釋的解釋，目的是為了能夠“write alternately”

b) 每個checkpint field需要的大小空間為304位元組。(相關定義在log0log.h)

c) 第一個checkpoint的起始位置在ib_logfile0的第512位元組(OS_FILE_LOG_BLOCK_SIZE)處；

d) “第二個在1536 (3 * OS_FILE_LOG_BLOCK_SIZE)位元組處” [1]

Redo log文件以ib_logfile[number]命名，日誌目錄可以通過參數innodb_log_group_home_dir控制。Redo log以順序的方式寫入文件文件，寫滿時則回溯到第一個文件，進行覆蓋寫。（但在做redo checkpoint時，也會更新第一個日誌文件的頭部checkpoint標記，所以嚴格來講也不算順序寫）。

“在InnoDB內部，邏輯上ib_logfile被當成了一個文件，對應同一個space id。由於是使用512位元組block對齊寫入文件，可以很方便的根據全局維護的LSN號計算出要寫入到哪一個文件以及對應的偏移量。”[2]

總結

8.0 一個自動提交事務，redo落文件的方式追蹤 1.通過後臺線程thread/innodb/log_writer_thread 寫redo，通過另一個後臺線程thread/innodb/log_checkpointer_thread ，在ib_logfile0的pos=512 pos=1536 ，分別記錄checkpoint 。兩個線程都是以512B的整數倍為單位，寫文件。

追蹤過程比結論重要。sysdig在可觀測性方面提供了強大的幫助。理論聯繫實際，才是探索未知事務之道。

最後感謝GreatSQL社區，對本文出爐給與的技術支持。

Enjoy GreatSQL

您的分享是我們最大的動力!

-Advertisement-
Play Games
更多相關文章
  • Python 博客園備份遷移腳本
    鑒於有些小伙伴在尋找博客園遷移到個人博客的方案，本人針對博客園實現了一個自動備份腳本，可以快速將博客園中自己的文章備份成Markdown格式的獨立文件，備份後的md文件可以直接放入到hexo博客中，快速生成自己的站點，而不需要自己逐篇文章遷移，提高了備份文章的效率。 ...
  • 學習ASP.NET Core Blazor編程系列二——第一個Blazor應用程式（中）
    【問題】為什麼 System.Timers.Timer 更改間隔時間後的第一次觸發時間是設定時間的三倍？ 獨立觀察員 2022 年 9 月 4 日 在編寫 “Wifi 固定器 [1]” 程式時，按如下方式使用了定時器： //聲明; private Timer _Timer = new Timer() ...
  • .Net下的Http請求調用(Post與Get)
    http請求調用是開發中經常會用到的功能。在內，調用自有項目的Web Api等形式介面時會用到；在外，調用一些第三方功能介面時，也會用到，因為，這些第三方功能往往是通過http地址的形式提供的，比如：簡訊服務、線上翻譯、地圖服務、語音智能、等… http請求調用，又分為Post與Get兩種形式。（支 ...
  • 踩坑之旅：配置 ROS 環境
    最近在學習機器人相關的導航演算法，為了方便於驗證演算法的效果，需要搭一個 ROS(Robot Operate System) 環境。特地寫點筆記，這是這個機器人系列的首篇筆記。 ...
  • 關於MicroPython mpremote工具 的一些用例，閑聊
    我嘗試了很多不同的第三方micropython工具，有些是Windows應用程式，有些是VScode插件。 但是當我嘗試過MicroPython的mpremote工具後，我幾乎決定它將成為我的首選工具。😄 我通常將其與VScode結合使用。它的代碼突出顯示，自動完成和自動縮進非常有用。同時打開其他 ...
  • 【必知必會】手把手教你配置MySQL環境變數——圖文詳解
    一、先決條件 假設我們已經成功安裝MySQL資料庫。如果還有小伙伴不知道如何安裝MySQL資料庫，可以在本文下留言，留言數超20，則出一期“手把手教你安裝MySQL資料庫——圖文詳解”的文章。 二、登錄MySQL 當 MySQL 服務已經運行時，我們可以通過命令提示符（cmd）視窗登錄到 MySQL ...
  • MySQL第三天
    2022-09-05 MySQL常用的命令語句 表的操作語句 1、查詢某個表的內容 select * from xxx(表名); 2、向某個表內添加數據 以“students”表為例： students表的屬性有：id,name,age,sex insert into students values ...
  • 深度乾貨！一篇Paper帶您讀懂HTAP | StoneDB學術分享會第①期
    在最新一屆國際資料庫頂級會議 ACM SIGMOD 2022 上，來自清華大學的李國良和張超兩位老師發表了一篇論文：《HTAP Database: What is New and What is Next》,並做了 《HTAP Database：A Tutorial》 的專項報告。 本篇文章，我們將 ...
一周排行
    -Advertisement-
    Play Games
  • 移動開發（一）：使用.NET MAUI開發第一個安卓APP
    移動開發（一）：使用.NET MAUI開發第一個安卓APP 對於工作多年的C#程式員來說，近來想嘗試開發一款安卓APP，考慮了很久最終選擇使用.NET MAUI這個微軟官方的框架來嘗試體驗開發安卓APP，畢竟是使用Visual Studio開發工具，使用起來也比較的順手，結合微軟官方的教程進行了安卓 ...
  • wpf ToggleButton選中效果和一個登錄界面
    前言 QuestPDF 是一個開源 .NET 庫，用於生成 PDF 文檔。使用了C# Fluent API方式可簡化開發、減少錯誤並提高工作效率。利用它可以輕鬆生成 PDF 報告、發票、導出文件等。 項目介紹 QuestPDF 是一個革命性的開源 .NET 庫，它徹底改變了我們生成 PDF 文檔的方 ...
  • 彈幕樹洞項目功能新增篇
    項目地址 項目後端地址： https://github.com/ZyPLJ/ZYTteeHole 項目前端頁面地址： ZyPLJ/TreeHoleVue (github.com) https://github.com/ZyPLJ/TreeHoleVue 目前項目測試訪問地址： http://tree ...
  • 第27篇 sqlserver2022詳細安裝步驟
    話不多說，直接開乾 一.下載 1.官方鏈接下載： https://www.microsoft.com/zh-cn/sql-server/sql-server-downloads 2.在下載目錄中找到下麵這個小的安裝包 SQL2022-SSEI-Dev.exe，運行開始下載SQL server； 二. ...
  • .NET 開源高性能 MQTT 類庫
    前言 隨著物聯網（IoT）技術的迅猛發展，MQTT（消息隊列遙測傳輸）協議憑藉其輕量級和高效性，已成為眾多物聯網應用的首選通信標準。 MQTTnet 作為一個高性能的 .NET 開源庫，為 .NET 平臺上的 MQTT 客戶端與伺服器開發提供了強大的支持。 本文將全面介紹 MQTTnet 的核心功能 ...
  • Serilog文檔翻譯系列（六） - 可用的接收器、增強器、格式化輸出
    Serilog支持多種接收器用於日誌存儲，增強器用於添加屬性，LogContext管理動態屬性，支持多種輸出格式包括純文本、JSON及ExpressionTemplate。還提供了自定義格式化選項，適用於不同需求。 ...
  • 警惕 Visual Studio 屬性求值副作用導致邏輯不符合預期
    目錄簡介獲取 HTML 文檔解析 HTML 文檔測試參考文章 簡介 動態內容網站使用 JavaScript 腳本動態檢索和渲染數據，爬取信息時需要模擬瀏覽器行為，否則獲取到的源碼基本是空的。 本文使用的爬取步驟如下： 使用 Selenium 獲取渲染後的 HTML 文檔 使用 HtmlAgility ...
  • [使用目前最新版]HybridCLR6.9.0+YooAsset2.2.4實現純C# Unity熱更新方案 (一)
    1.前言 什麼是熱更新 游戲或者軟體更新時，無需重新下載客戶端進行安裝，而是在應用程式啟動的情況下，在內部進行資源或者代碼更新 Unity目前常用熱更新解決方案 HybridCLR，Xlua，ILRuntime等 Unity目前常用資源管理解決方案 AssetBundles，Addressable， ...
  • 在 ASP.NET Core Web API 中使用操作篩選器統一處理通用操作
    本文章主要是在C# ASP.NET Core Web API框架實現向手機發送驗證碼簡訊功能。這裡我選擇是一個互億無線簡訊驗證碼平臺，其實像阿裡雲，騰訊雲上面也可以。 首先我們先去 互億無線 https://www.ihuyi.com/api/sms.html 去註冊一個賬號 註冊完成賬號後，它會送 ...
  • 第28篇 如何.net中實現高效可靠數據同步api
    通過以下方式可以高效，並保證數據同步的可靠性 1.API設計 使用RESTful設計，確保API端點明確，並使用適當的HTTP方法（如POST用於創建，PUT用於更新）。 設計清晰的請求和響應模型，以確保客戶端能夠理解預期格式。 2.數據驗證 在伺服器端進行嚴格的數據驗證，確保接收到的數據符合預期格 ...
所有分類