Långsam MySQL-starttid i GTID-läge? Storleken på binär loggfil kan vara problemet

Har du upplevt långsamma MySQL-starttider i GTID-läge? Vi stötte nyligen på det här problemet på en av våra MySQL-värdinstallationer och försökte lösa problemet. I den här bloggen delar vi upp problemet som kan sänka dina MySQL-omstartstider, hur du felsöker för din implementering och vad du kan göra för att minska din starttid och förbättra din förståelse av GTID-baserad replikering.

Hur vi hittade problemet

Vi undersökte långsamma MySQL-starttider på en low-end, diskbaserad MySQL 5.7.21-distribution som hade GTID-läge aktiverat. Systemet var en del av ett master-slav-par och var under en måttlig skrivbelastning. Vid omstart under ett planerat underhåll märkte vi att databasservern tog 5-10 minuter att starta upp och börja acceptera anslutningar. Den typen av förseningar var inte meningsfulla, så vi gav oss ut för att undersöka.

Felsöka din långsamma MySQL-starttid

Vi använde det populära Percona-verktyget pt-ioprofile för att se vad databasen gjorde. pt-ioprofile är ett mycket viktigt verktyg i Perconas populära verktygslåda som används för att felsöka MySQL-problem, och du kan se hela listan med funktioner i deras dokumentation. pt-ioprofilen verktyget använder strace och lsof för att titta på en processs I/O och skriva ut en tabell över filer och I/O-aktivitet.

Så vi startade MySQL, väntade på mysqld process för att skapas och startade pt-ioprofile för att se vad problemet kan vara:

# pt-ioprofile --profile-process mysqld --run-time 200
Tue Oct 9 15:42:24 UTC 2018
Tracing process ID 18677
total      pread       read     pwrite      write      fsync  fdatasync       open      close   getdents      lseek      fcntl filename
...
216.550641   0.000000  216.550565   0.000000   0.000000   0.000000   0.000000   0.000015   0.000040   0.000000   0.000021   0.000000 /mysql_data/binlogs/mysql-bin.000014
...

Vad gör att din MySQL-omstart går långsammare?

När vi körde detta flera gånger såg vi följande:

mysqld processen ägnade det mesta av sin tid åt att läsa den senaste binära loggfilen. Detta var fallet även när servern hade stoppats på ett elegant sätt och det inte fanns något behov av en kraschåterställning osv.
Servern tillbringade också avsevärd tid med att ladda InnoDB-datafilerna, men den tiden var mycket kortare jämfört med tiden som gick åt till att läsa den senaste binära loggfilen.
Om servern startades om igen omedelbart skulle denna efterföljande omstart gå mycket snabbare.
Eftersom en databasavstängning rensar den binära loggen och skapar en ny vid start, gjorde vi ytterligare ett experiment – innan vi stängde av servern rensade vi de binära loggarna. Den efterföljande serverstarten gick snabbt igen.

Dessa observationer pekade tydligt på det faktum att MySQL ägnade mycket tid åt att läsa den senaste binära loggfilen. Om filen var liten, som den skulle vara när loggfilen rensades innan en avstängning, gick uppstarten snabbt.

Långsam MySQL-starttid i GTID? Din binära loggfilstorlek kan vara problemet. Klicka för att tweeta

Förstå Binlog GTID-återställning

Som det visar sig, för att fylla i värdena för gtid_executed och gtid_purged, måste MySQL-servern analysera de binära loggfilerna.

Här är sammanfattningen av MySQL 5.7-dokumentationsmetodens rekommendation baserad på en FALSK eller SANN läsning:

När binlog_gtid_simple_recovery =FALSKT:

För att beräkna gtid_executed:

Iterera binära loggfiler från de senaste, och stanna vid den första filen som har en Previous_gtids_log_event inträde.
Använd alla GTID från Previous_gtids_log_event och Gtid_log_events från denna binära loggfil och lagra denna GTID-uppsättning internt. Det kallas gtids_in_binlog.
Värde på gtid_executed beräknas som föreningen av gtids_in_binlog och GTID i tabellen mysql.gtid_executed .

Den här processen kan vara mycket tidskrävande om det finns ett stort antal binära loggfiler utan GTID, till exempel skapade när gtid_mode =AV.

På liknande sätt, för att beräkna gtid_purged:

Iterera binära loggfiler från de äldsta till de senaste, och stanna vid den första binära loggen som innehåller antingen en icke-tom Previous_gtids_log_event (har minst ett GTID), eller som har minst en Gtid_log_event .
Läs Previous_gtids_log_event från denna fil. Beräkna den interna variabeln gtids_in_binlog_not_purged eftersom denna GTID-uppsättning subtraheras från gtids_in_binlog.
Värde på gtid_purged är inställd på gtid_executed , minus gtids_in_binlog_not_purged .

Så detta utgör grunden för vår förståelse för hur saker och ting fungerade förut i äldre versioner. Vissa optimeringar kan dock göras när binlog_gtid_simple_recovery är sant. Det här är fallet vi är intresserade av:

När binlog_gtid_simple_recovery =SANT:

(Obs, detta är standard i MySQL 5.7.7 och senare)

Läs bara de äldsta och de senaste binära loggfilerna.
Compute gtid_purged från Previous_gtids_log_event eller Gtid_log_event finns i den äldsta binära loggfilen.
Beräkning gtid_exekverad från Previous_gtids_log_event eller Gtid_log_event hittas i den senaste binära loggfilen.
Därmed är endast två binära loggfiler läses under serverns omstart eller när binära loggar rensas.

Så, för MySQL version 5.7.7 och högre, läses de senaste och gamla binära loggfilerna alltid under systemstart för att korrekt initiera GTID-systemvariabler. Att läsa den äldsta binära loggfilen är inte lika dyrt eftersom händelsen MySQL letar efter, Previous_gtids_log_event, alltid är den första händelsen i en binär loggfil.

Men för att korrekt beräkna gtid_executed , måste servern läsa igenom hela den senaste binära loggfilen och samla alla händelser i den filen. Så systemets starttid blir direkt proportionell mot storleken på den senaste binära loggfilen .

Observera att situationen är ännu värre när binlog_gtid_simple_recovery är FALSKT . Eftersom det inte längre är standardalternativet i de senaste utgåvorna är det inte särskilt bekymmersamt.

Så löser du din långsamma starttid

Efter att ha förstått orsaken till problemet vi stötte på var lösningen vi bestämde oss för ganska uppenbar – minska storleken på de binära loggfilerna. Standardstorleken för binära loggfiler är 1 GB. Det tar tid att analysera en fil av denna storlek under uppstart, så det är vettigt att minska värdet på max_binlog_size till ett lägre värde.

Om det inte är ett alternativ att minska storleken på den binära loggfilen, kan det hjälpa att tömma de binära loggfilerna precis innan en underhållsavstängning av mysqld-processen för att minska återställningstiderna för binlog GTID.