Redis Full Synchronization Disk-to-Disk

레디스 서버 교육 신청 레디스 정기점검/기술지원
Redis Technical Support 		레디스 엔터프라이즈 서버
Redis Enterprise Server

Overview

이 문서는 Redis 버전 7.0.8을 기준으로 작성했습니다.
키 개수는 약 1천만개이고 메모리는 1Gb입니다.

Overview

Full Sync Disk-Disk
  • rdb-del-sync-files no : Master/Replica의 rdb 파일을 지울지 여부를 정한다. 6.0에서 추가
    Yes면 삭제. 이 옵션은 AOF와 RDB(save)가 모두 비활성화된 상태에서만 작동합니다.
    규제(regulations) 또는 기타 보안 문제로 디스크에 데이터를 남기지 않을 경우 사용합니다.

로그

일시 표기 변경: 유럽식에서 ISO 표준으로 변경했고, 로그의 정확한 시각을 표기하려고 millisecond에서 microsecond로 변경했습니다.

Master Log 
32221:M 2023-02-27 10:32:21.512204 * Replica 127.0.0.1:18505 asks for synchronization
32221:M 2023-02-27 10:32:21.512255 * Partial resynchronization not accepted: 
   Replication ID mismatch (Replica asked for '8527610751db040f683426b45f82d875d37f455b', 
   my replication IDs are 'ccac3ea676564a1bd64410095df68e801434681a' and 
   '0000000000000000000000000000000000000000')
32221:M 2023-02-27 10:32:21.512294 * Replication backlog created, 
   my new replication IDs are '6c51a9e46110e675f249ffb3b91ee82d825efa2b' and 
   '0000000000000000000000000000000000000000'
32221:M 2023-02-27 10:32:21.512321 * Starting BGSAVE for SYNC with target: disk
32221:M 2023-02-27 10:32:21.525410 * Background saving started by pid 32333
32333:C 2023-02-27 10:32:25.579347 * DB saved on disk
32333:C 2023-02-27 10:32:25.588843 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
32221:M 2023-02-27 10:32:25.615219 * Background saving terminated with success
32221:M 2023-02-27 10:32:26.511645 * Synchronization with replica 127.0.0.1:18505 succeeded
32221:M 2023-02-27 10:32:31.699392 * (Received REPLCONF ACK 0)
Replica Log 
32279:S 2023-02-27 10:32:21.511306 * Before turning into a replica, using my own master parameters to 
   synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
32279:S 2023-02-27 10:32:21.511364 * Connecting to MASTER 127.0.0.1:18504
32279:S 2023-02-27 10:32:21.511452 * MASTER <-> REPLICA sync started
32279:S 2023-02-27 10:32:21.511514 * REPLICAOF 127.0.0.1:18504 enabled (user request from 'id=4 
   addr=127.0.0.1:32994 laddr=127.0.0.1:18505 fd=11 name= age=0 idle=0 flags=N db=0 sub=0 
   psub=0 ssub=0 multi=-1 qbuf=45 qbuf-free=20429 argv-mem=23 multi-mem=0 rbs=16384 rbp=16384 
   obl=0 oll=0 omem=0 tot-mem=37679 events=r cmd=replicaof user=default redir=-1 resp=2')
32279:S 2023-02-27 10:32:21.511652 * Non blocking connect for SYNC fired the event.
32279:S 2023-02-27 10:32:21.511906 * Master replied to PING, replication can continue...
32279:S 2023-02-27 10:32:21.512100 * Trying a partial resynchronization 
   (request 8527610751db040f683426b45f82d875d37f455b:1).
32279:S 2023-02-27 10:32:21.525583 * Full resync from master: 
   6c51a9e46110e675f249ffb3b91ee82d825efa2b:0
32279:S 2023-02-27 10:32:25.615348 * MASTER <-> REPLICA sync: 
   receiving 388011570 bytes from master to disk
32279:S 2023-02-27 10:32:26.521962 * Discarding previously cached master state.
32279:S 2023-02-27 10:32:26.522016 * MASTER <-> REPLICA sync: Flushing old data
32279:S 2023-02-27 10:32:26.524074 * MASTER <-> REPLICA sync: Loading DB in memory
32279:S 2023-02-27 10:32:26.799299 * Loading RDB produced by version 7.0.8
32279:S 2023-02-27 10:32:26.799357 * RDB age 5 seconds
32279:S 2023-02-27 10:32:26.799410 * RDB memory usage when created 963.86 Mb
32279:S 2023-02-27 10:32:31.687766 * Done loading RDB, keys loaded: 9949010, keys expired: 0.
32279:S 2023-02-27 10:32:31.687885 * MASTER <-> REPLICA sync: Finished with success
32279:S 2023-02-27 10:32:31.699320 * (Send REPLCONF ACK 0)

흐름도

Full Sync Disk-Disk

로그

마스터와 복제본의 로그를 처리 시간순으로 배열했습니다.
마스터 로그는 왼쪽에, 복제본 로그는 약간 오른쪽에 배치했습니다.
(로그에 시분초는 유지했고, process id와 년월일을 제거했습니다)

Replica Log
10:32:21.511306 * Before turning into a replica, using my own master parameters to synthesize ... 
10:32:21.511364 * Connecting to MASTER 127.0.0.1:18504
10:32:21.511452 * MASTER <-> REPLICA sync started
10:32:21.511514 * REPLICAOF 127.0.0.1:18504 enabled (user request from 'id=4 addr=127....
10:32:21.511652 * Non blocking connect for SYNC fired the event.
10:32:21.511906 * Master replied to PING, replication can continue...
10:32:21.512100 * Trying a partial resynchronization (request 8527610751db040f683426...:1).
Master Log
10:32:21.512204 * Replica 127.0.0.1:18505 asks for synchronization
10:32:21.512255 * Partial resynchronization not accepted: Replication ID mismatch ...
10:32:21.512294 * Replication backlog created, my new replication IDs are '6c51...'
10:32:21.512321 * Starting BGSAVE for SYNC with target: disk
                                  Send "+FULLRESYNC replid offset" to replica
Replica Log
10:32:21.525583 * Full resync from master: 6c51a9e46110e675f249ffb3b91ee82d825efa2b:0
Master Log
10:32:21.525410 * Background saving started by pid 32333
Child Process
--- 데이터를 파일에 저장하는데 4초 걸렸다. ---
10:32:25.579347 * DB saved on disk
10:32:25.588843 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
Parent Process
10:32:25.615219 * Background saving terminated with success
Replica Log
10:32:25.615348 * MASTER <-> REPLICA sync: receiving 388011570 bytes from master to disk
Master Log
10:32:26.511645 * Synchronization with replica 127.0.0.1:18505 succeeded
Replica Log
10:32:26.521962 * Discarding previously cached master state.
10:32:26.522016 * MASTER <-> REPLICA sync: Flushing old data
10:32:26.524074 * MASTER <-> REPLICA sync: Loading DB in memory
10:32:26.799299 * Loading RDB produced by version 7.0.8
10:32:26.799357 * RDB age 5 seconds
10:32:26.799410 * RDB memory usage when created 963.86 Mb
10:32:31.687766 * Done loading RDB, keys loaded: 9949010, keys expired: 0.
10:32:31.687885 * MASTER <-> REPLICA sync: Finished with success
10:32:31.699320 * (Send REPLCONF ACK 0)
Master Log
10:32:31.699392 * (Received REPLCONF ACK 0)

자세한 흐름도

마스터와 복제본의 상호 작용을 함수와 로그로 자세히 표시했습니다.

Full Sync Disk-Disk Full Sync Disk-Disk Full Sync Disk-Disk

로그

Replica Log
void replicaofCommand(client *c) replication.c
   replicationSetMaster(c->argv[1]->ptr, port) replication.c
      void replicationCacheMasterUsingMyself(void) replication.c
         "Before turning into a replica, using my own master parameters to synthesize a cached master"
      "Connecting to MASTER 127.0.0.1:18504"
      int connectWithMaster(void)	replication.c	
	  connConnect(server.repl_transfer_s, ip, port, bind_source_addr, syncWithMaster)
         "MASTER <-> REPLICA sync started"
   "REPLICAOF 127.0.0.1:18504 enabled (user request from ...)"
       void syncWithMaster(connection *conn)	replication.c	
          "Non blocking connect for SYNC fired the event." 
          connSetReadHandler(conn, syncWithMaster);
          connSetWriteHandler(conn, NULL);
          sendCommand(conn,"PING",NULL);
          "Master replied to PING, replication can continue..."
          sendCommandArgv(conn, argc, args, lens);  masteruser, masterauth
          sendCommand(conn,"REPLCONF","listening-port",portstr, NULL);
          sendCommand(conn,"REPLCONF", "capa","eof","capa","psync2",NULL);
          int slaveTryPartialResynchronization(conn, 0)		replication.c
            "Trying a partial resynchronization" 
             sendCommand(conn,"PSYNC",psync_replid,psync_offset,NULL);
Master Log
void syncCommand(client *c) 	replication.c 	
   "Replica 127.0.0.1:18505 asks for synchronization" 
   masterTryPartialResynchronization(c, psync_offset)  replication.c 	
      "Partial resynchronization not accepted: Replication ID mismatch"
   "Replication backlog created, my new replication IDs are"
   startBgsaveForReplication(c->slave_capa, c->slave_req) 	replication.c  	
      "Starting BGSAVE for SYNC with target: disk"  
      rdbSaveBackground(req, filename, rsiptr)	rdb.c
      replicationSetupSlaveForFullResync()
         Send "+FULLRESYNC replid offset" to replica
Replica Log
slaveTryPartialResynchronization(conn, 1) 	replication.c
   receiveSynchronousResponse(conn);
   "Full resync from master: 6c51a9e46110e675f249ffb3b91ee82d825efa2b:0"
connSetReadHandler(conn,readSyncBulkPayload);
Master Log
rdbSaveBackground(req, filename, rsiptr)	rdb.c
   redisFork() 
   Parent Process
      "Background RDB transfer started by pid 32333" 
   Child Process
      rdbSave()	rdb.c
         startSaving()
         rdbSaveRio()
         "DB saved on disk"
         stopSaving(1)
      sendChildCowInfo()	server.c     
         sendChildInfoGeneric() 	childinfo.c
            "Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB" 
      exitFromChild()			
Parent Process
serverCron() server.c
checkChildrenDone() 1초마다 실행(Time Event) server.c	  
   backgroundSaveDoneHandler()  rdb.c
       static void backgroundSaveDoneHandlerDisk(int exitcode, int bysignal)	rdb.c
          "Background saving terminated with success"
	   void updateSlavesWaitingBgsave(int bgsaveerr, int type)	replication.c
	      connSetWriteHandler(sendBulkToSlave) replication.c
		  sendBulkToSlave() // 데이터를 읽어서 복제본에 보낸다. 
		     lseek(), read(), connWrite()
Replica Log
void readSyncBulkPayload(connection *conn) replication.c
  "MASTER <-> REPLICA sync: receiving 388011570 bytes from master to disk"
Master Log
int replicaPutOnline(client *slave) replication.c
  "Synchronization with replica 127.0.0.1:18505 succeeded"
replicaStartCommandStream()
// 이 시점에 fork()이후 누적된 데이터를 보내고, 실시간으로 데이터를 복제본에 보낸다.
Replica Log
replicationAttachToNewMaster() 	replication.c
   void replicationDiscardCachedMaster(void)	replication.c
      "Discarding previously cached master state."
void readSyncBulkPayload(connection *conn)	replication.c
  "MASTER <-> REPLICA sync: Flushing old data"  기존 데이터 삭제 
  emptyData(-1);
  "MASTER <-> REPLICA sync: Loading DB in memory"  데이터를 받아서 메모리에 적재 시작
  fsync(server.repl_transfer_fd);
  open(server.rdb_filename,...);
  rename(tmpfile, filename);
  fsyncFileDir(filename);
  rdbLoad(filename);
    fopen();
    startLoadingFile();  startLoad();  { server.loading = 1; server.loading_start_time = time(NULL); }
    rioInitWithFile();   // file로 부터 읽는다.
    rdbLoadRio()
      int rdbLoadRioWithLoadingCtx(rio *rdb, int rdbflags, rdbSaveInfo *rsi, rdbLoadingCtx *rdb_loading_ctx) rdb.c
        rioRead(rdb);
        다음 3줄은 RDB 데이터 헤더를 읽고 로그를 남긴 것임.
        "Loading RDB produced by version 7.0.8"  RDB 데이터가 레디스 버전 7.0.8에서 만들어졌음.
        "RDB age 0 seconds"  마스터에서 0초 전에 만들어졌음.
        "RDB memory usage when created 0.98 Mb"  데이터를 만드는데 0.98Mb 메모리가 사용되었음.
        While(1) loop를 돌면서 데이터를 받아서 메모리에 적재함. EOF를 만나면 loop를 종료함.
        "Done loading RDB, keys loaded: 0, keys expired: 0."
      fclose();
      stopLoading();	{ server.loading = 0; }   
  "MASTER <-> REPLICA sync: Finished with success"
  if (usemark) replicationSendAck();  -> REPLCONF ACK 
  if (server.aof_enabled) restartAOFAfterSYNC();
Master Log
replconfCommand() replication.c
  (Received REPLCONF ACK 0)

<< Full Sync Intro Full Sync Mem-to-Disk >>

Email 답글이 올라오면 이메일로 알려드리겠습니다.
Email redisgate@gmail.com Address 서울시 강남구 강남대로 342 역삼빌딩 5층 (역삼동) 우 06242 Telephone 02.503.2235 Copyright © 2014-2024 redisGate
All right reserved