Redis Full Synchronization Memory-to-Disk

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

Overview

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

Overview

Full Sync Memory-Disk
  • 다음 3개 파라미터는 마스터에 적용되는 옵션이다.
  • repl-diskless-sync no or yes : 3.0에 추가, 6.x까지 default no, 7.0부터 yes
  • repl-diskless-sync-delay 5 <seconds> 두번째 복제본의 요청을 기다린다.
    5초 내로 전체 동기화 요청이 오면 첫번째 복제본과 같이 데이터를 전송한다.
    파일 저장 전송(Disk-Disk)일 경우 파일을 저장하는 동안 요청이 들어오면 여러 복제본에 한번에 전송한다. 이러한 효과를 유지하려고 이 파라이터를 만들었다.
  • repl-diskless-sync-max-replicas 0 : 0은 delay 5초를 기다리고, 2로 설정하면 5초가 되지 않았어도 2개의 replica가 full sync를 요청하면 바로 전달한다. 7.0에서 추가

로그

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

Master Log 
15958:M 2023-02-27 10:10:58.005810 * Replica 127.0.0.1:18505 asks for synchronization
15958:M 2023-02-27 10:10:58.005863 * Partial resynchronization not accepted: 
   Replication ID mismatch (Replica asked for '05be3d5a2a4bf277b9308f259e3acdffa769b6d1', 
   my replication IDs are 'f94df0cb471c240c46b97db0b03f549ca3bed26f' and 
   '0000000000000000000000000000000000000000')
15958:M 2023-02-27 10:10:58.005915 * Replication backlog created, 
   my new replication IDs are '6d1b6c0382da7de05546d8e7c260d4a49187a74e' and 
   '0000000000000000000000000000000000000000'
15958:M 2023-02-27 10:10:58.005954 * Delay next BGSAVE for diskless SYNC
15958:M 2023-02-27 10:11:03.805858 * Starting BGSAVE for SYNC with target: replicas sockets
15958:M 2023-02-27 10:11:03.819060 * Background RDB transfer started by pid 16083
16083:C 2023-02-27 10:11:07.421776 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
15958:M 2023-02-27 10:11:07.421832 # Diskless rdb transfer, done reading from pipe, 1 replicas still up.
15958:M 2023-02-27 10:11:07.527382 * Background RDB transfer terminated with success
15958:M 2023-02-27 10:11:07.527460 * Streamed RDB transfer with replica 127.0.0.1:18505 succeeded (socket). 
   Waiting for REPLCONF ACK from slave to enable streaming
15958:M 2023-02-27 10:11:07.527478 * Synchronization with replica 127.0.0.1:18505 succeeded
Replica Log 
15998:S 2023-02-27 10:10:58.005019 * 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.
15998:S 2023-02-27 10:10:58.005072 * Connecting to MASTER 127.0.0.1:18504
15998:S 2023-02-27 10:10:58.005174 * MASTER <-> REPLICA sync started
15998:S 2023-02-27 10:10:58.005226 * REPLICAOF 127.0.0.1:18504 enabled (user request from 'id=6 
   addr=127.0.0.1:46058 laddr=127.0.0.1:18505 fd=11 name= age=28 idle=1 flags=N db=0 sub=0 
   psub=0 ssub=0 multi=-1 qbuf=45 qbuf-free=20429 argv-mem=23 multi-mem=0 rbs=1024 rbp=0 
   obl=0 oll=0 omem=0 tot-mem=22319 events=r cmd=replicaof user=default redir=-1 resp=2')
15998:S 2023-02-27 10:10:58.005299 * Non blocking connect for SYNC fired the event.
15998:S 2023-02-27 10:10:58.005495 * Master replied to PING, replication can continue...
15998:S 2023-02-27 10:10:58.005678 * Trying a partial resynchronization 
   (request 05be3d5a2a4bf277b9308f259e3acdffa769b6d1:1).
15998:S 2023-02-27 10:11:03.806075 * Full resync from master: 
   6d1b6c0382da7de05546d8e7c260d4a49187a74e:14
15998:S 2023-02-27 10:11:03.829715 * MASTER <-> REPLICA sync: 
   receiving streamed RDB from master with EOF to disk
15998:S 2023-02-27 10:11:07.421924 * Discarding previously cached master state.
15998:S 2023-02-27 10:11:07.421949 * MASTER <-> REPLICA sync: Flushing old data
15998:S 2023-02-27 10:11:11.066119 * MASTER <-> REPLICA sync: Loading DB in memory
15998:S 2023-02-27 10:11:11.071316 * Loading RDB produced by version 7.0.8
15998:S 2023-02-27 10:11:11.071344 * RDB age 8 seconds
15998:S 2023-02-27 10:11:11.071363 * RDB memory usage when created 963.91 Mb
15998:S 2023-02-27 10:11:16.032246 * Done loading RDB, keys loaded: 9949010, keys expired: 0.
15998:S 2023-02-27 10:11:16.032321 * MASTER <-> REPLICA sync: Finished with success
15998:S 2023-02-27 10:11:16.032340 * (Send REPLCONF ACK 0)

흐름도

흐름도

Full Sync Memory-Disk

로그

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

Replica Log
10:10:58.005019 * Before turning into a replica, using my own master parameters to synthesize ...
10:10:58.005072 * Connecting to MASTER 127.0.0.1:18504
10:10:58.005174 * MASTER <-> REPLICA sync started
10:10:58.005226 * REPLICAOF 127.0.0.1:18504 enabled (user request from 'id=6 addr=127....
10:10:58.005299 * Non blocking connect for SYNC fired the event.
10:10:58.005495 * Master replied to PING, replication can continue...
10:10:58.005678 * Trying a partial resynchronization (request 05be3d5a2a4bf277...:1).
Master Log
10:10:58.005810 * Replica 127.0.0.1:18505 asks for synchronization
10:10:58.005863 * Partial resynchronization not accepted: Replication ID mismatch ...
10:10:58.005915 * Replication backlog created, my new replication IDs are '6d1b...' 
10:10:58.005954 * Delay next BGSAVE for diskless SYNC
--- 다른 동기화 요청이 있을지 5초 동안 기다림 ---
10:11:03.805858 * Starting BGSAVE for SYNC with target: replicas sockets
                                  Send "+FULLRESYNC replid offset" to replica
Replica Log
10:11:03.806075 * Full resync from master: 6d1b6c0382da7de05546d8e7c260d4a49187a74e:14
Master Log
10:11:03.819060 * Background RDB transfer started by pid 16083
Replica Log
10:11:03.829715 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk
Master Log
--- Rdb 데이터를 복제본에 보내는데 4초 걸림 ---
Child Process
10:11:07.421776 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
Parent Process
10:11:07.421832 # Diskless rdb transfer, done reading from pipe, 1 replicas still up.
Replica Log
10:11:07.421924 * Discarding previously cached master state.
10:11:07.421949 * MASTER <-> REPLICA sync: Flushing old data
Master Log
10:11:07.527382 * Background RDB transfer terminated with success
10:11:07.527460 * Streamed RDB transfer with replica 127.0.0.1:18505 succeeded (socket).
    Waiting for REPLCONF ACK from slave to enable streaming
10:11:07.527478 * Synchronization with replica 127.0.0.1:18505 succeeded
Replica Log
--- Old data flush 하는데 4초 걸림 ---
10:11:11.066119 * MASTER <-> REPLICA sync: Loading DB in memory
10:11:11.071316 * Loading RDB produced by version 7.0.8
10:11:11.071344 * RDB age 8 seconds
10:11:11.071363 * RDB memory usage when created 963.91 Mb
--- Data loading 하는데 5초 걸림 ---
10:11:16.032246 * Done loading RDB, keys loaded: 9949010, keys expired: 0.
10:11:16.032321 * MASTER <-> REPLICA sync: Finished with success

자세한 흐름도

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

Full Sync Memory-Disk Full Sync Memory-Disk Full Sync Memory-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	
         "MASTER <-> REPLICA sync started"
   "REPLICAOF 127.0.0.1:18504 enabled (user request from ...)"
      int connectWithMaster(void)	replication.c	
         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"
   "Delay next BGSAVE for diskless SYNC" repl-diskless-sync-delay 5 -> 5초를 기다린다.
   startBgsaveForReplication(c->slave_capa, c->slave_req) 	replication.c  	
      "Starting BGSAVE for SYNC with target: replicas sockets"  
      rdbSaveToSlavesSockets(req, rsiptr)	rdb.c
         replicationSetupSlaveForFullResync()
            Send "+FULLRESYNC replid offset" to replica
Replica Log
int slaveTryPartialResynchronization(connection *conn, int read_reply) replication.c
  "Full resync from master: 6d1b6c0382da7de05546d8e7c260d4a49187a74e:14"
Master Log
int rdbSaveToSlavesSockets(int req, rdbSaveInfo *rsi)	rdb.c
   redisFork() 
   Parent Process
      "Background RDB transfer started by pid 16083" 
   Child Process
      rdbSaveRioWithEOFMark()  
         startSaving()
         rioWrite(“$EOF:eofmark”);  (Send(Start) EOF:9183d8d1d2950c95e00ad572404a54c2dbfaaf0f)
Replica Log
void readSyncBulkPayload(connection *conn) replication.c
  "MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to disk"
Master Log
Child Process
      rdbSaveRioWithEOFMark()  
         rdbSaveRio()
            rdbSaveDb()
         rioWrite(“$EOF:eofmark”);  (Send(End) EOF:9183d8d1d2950c95e00ad572404a54c2dbfaaf0f)			
         stopSaving(1)
   sendChildCowInfo()	server.c     
      void sendChildInfoGeneric(childInfoType info_type, size_t keys, double progress, char *pname) childinfo.c
         "Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB" 
Parent Process
void rdbPipeReadHandler(struct aeEventLoop *eventLoop, int fd, void *clientData, int mask) replication.c
   read() from Child process
   connWrite() to Replica
   "Diskless rdb transfer, done reading from pipe, 1 replicas still up."
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"  기존 데이터 삭제
Master Log
serverCron() server.c
checkChildrenDone() 1초마다 실행(Time Event) server.c	  
   backgroundSaveDoneHandler()  rdb.c
       static void backgroundSaveDoneHandlerSocket(int exitcode, int bysignal)	rdb.c
          "Background RDB transfer terminated with success"
	   void updateSlavesWaitingBgsave(int bgsaveerr, int type)	replication.c
          "Streamed RDB transfer with replica 127.0.0.1:18505 succeeded (socket). 
            Waiting for REPLCONF ACK from slave to enable streaming"
          int replicaPutOnline(client *slave)		replication.c
             "Synchronization with replica 127.0.0.1:18505 succeeded"
Replica Log
void readSyncBulkPayload(connection *conn)	replication.c
   "MASTER <-> REPLICA sync: Loading DB in memory"  데이터를 받아서 메모리에 적재 시작
   int rdbLoadRioWithLoadingCtx(rio *rdb, rdbflags, *rsi, *rdb_loading_ctx) rdb.c
      아래 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: 9949010, keys expired: 0."
   "MASTER <-> REPLICA sync: Finished with success"
   if (usemark) replicationSendAck();  -> REPLCONF ACK 
   if (server.aof_enabled) restartAOFAfterSYNC();
Master Log
replconfCommand()
if ("ack") {
   if (server.child_type == CHILD_TYPE_RDB && c->replstate == SLAVE_STATE_WAIT_BGSAVE_END)
      checkChildrenDone();
   if (c->repl_start_cmd_stream_on_ack && c->replstate == SLAVE_STATE_ONLINE)
      replicaStartCommandStream(c);
         putClientInPendingWriteQueue();
}

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

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