Redis Full Synchronization Memory-to-Memory

Redis Server 教育
Redis Server Course
Redis 定期点検/技術支援
Redis Technical Support
Redis エンタープライズサーバ
Redis Enterprise Server

Overview

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

Overview

Full Sync Memory-Memory
  • repl-diskless-load disabled/on-empty-db/swapdb 6.0에 추가
    복제본에 적용되는 옵션이다.
    • disabled: default 미적용
    • on-empty-db: 복제본에 기존 데이터가 없을 때 적용
    • swapdb: 복제본의 기존 데이터를 임시로 보관 -> 마스터의 데이터를 모두 받아 DB(메모리)에 저장 후, 임시로 보관한 기존 데이터를 삭제한다. 그러므로 두배의 메모리가 필요하다.

로그

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

Master Log
7492:M 2023-02-27 12:55:39.889362 * Replica 127.0.0.1:18505 asks for synchronization
7492:M 2023-02-27 12:55:39.889412 * Partial resynchronization not accepted: 
   Replication ID mismatch (Replica asked for 'bb412d2dd8fe6592b084a0921d92743af76bb408', 
   my replication IDs are '4727e5c85a163b80fd81b1d32a27bc9e1d70d2cd' and 
   '0000000000000000000000000000000000000000')
7492:M 2023-02-27 12:55:39.889450 * Replication backlog created, 
   my new replication IDs are '1c71f9cfa5cfd7a50ab7a76888d079dea71da179' and 
   '0000000000000000000000000000000000000000'
7492:M 2023-02-27 12:55:39.889472 * Delay next BGSAVE for diskless SYNC
7492:M 2023-02-27 12:55:44.928578 * Starting BGSAVE for SYNC with target: replicas sockets
7492:M 2023-02-27 12:55:44.942181 * Background RDB transfer started by pid 7526
7526:C 2023-02-27 12:55:44.942353 * (Send(Start) EOF:9183d8d1d2950c95e00ad572404a54c2dbfaaf0f)
7526:C 2023-02-27 12:55:49.842008 * (Send(End) EOF:9183d8d1d2950c95e00ad572404a54c2dbfaaf0f)
7526:C 2023-02-27 12:55:49.852363 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
7492:M 2023-02-27 12:55:49.859206 # Diskless rdb transfer, done reading from pipe, 1 replicas still up.
7492:M 2023-02-27 12:55:49.955488 * Background RDB transfer terminated with success
7492:M 2023-02-27 12:55:49.955509 * Streamed RDB transfer with replica 127.0.0.1:18505 succeeded (socket). 
   Waiting for REPLCONF ACK from slave to enable streaming
7492:M 2023-02-27 12:55:49.955551 * Synchronization with replica 127.0.0.1:18505 succeeded
7492:M 2023-02-27 12:55:49.975804 * (Received REPLCONF ACK 14)
Replica Log
7504:S 2023-02-27 12:55:39.888450 * 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.
7504:S 2023-02-27 12:55:39.888510 * Connecting to MASTER 127.0.0.1:18504
7504:S 2023-02-27 12:55:39.888625 * MASTER <-> REPLICA sync started
7504:S 2023-02-27 12:55:39.888727 * REPLICAOF 127.0.0.1:18504 enabled (user request from 'id=4 
   addr=127.0.0.1:36164 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')
7504:S 2023-02-27 12:55:39.888884 * Non blocking connect for SYNC fired the event.
7504:S 2023-02-27 12:55:39.889106 * Master replied to PING, replication can continue...
7504:S 2023-02-27 12:55:39.889242 * Trying a partial resynchronization 
   (request bb412d2dd8fe6592b084a0921d92743af76bb408:1).
7504:S 2023-02-27 12:55:44.928807 * Full resync from master: 
   1c71f9cfa5cfd7a50ab7a76888d079dea71da179:14
7504:S 2023-02-27 12:55:44.952917 * MASTER <-> REPLICA sync: 
   receiving streamed RDB from master with EOF to parser
7504:S 2023-02-27 12:55:44.952955 * MASTER <-> REPLICA sync: Loading DB in memory
7504:S 2023-02-27 12:55:44.952984 * Loading RDB produced by version 7.0.8
7504:S 2023-02-27 12:55:44.952998 * RDB age 0 seconds
7504:S 2023-02-27 12:55:44.953012 * RDB memory usage when created 963.87 Mb
7504:S 2023-02-27 12:55:49.952858 * Done loading RDB, keys loaded: 9949010, keys expired: 0.
7504:S 2023-02-27 12:55:49.952911 * Discarding previously cached master state.
7504:S 2023-02-27 12:55:49.952929 * MASTER <-> REPLICA sync: Swapping active DB with loaded DB
7504:S 2023-02-27 12:55:49.952954 * MASTER <-> REPLICA sync: Discarding old DB in background
7504:S 2023-02-27 12:55:49.952981 * MASTER <-> REPLICA sync: Finished with success
7504:S 2023-02-27 12:55:49.953024 * (Send REPLCONF ACK 14)

흐름도

흐름도

Full Sync Memory-Memory

로그

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

Replica Log
12:55:39.888450 * 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.
12:55:39.888510 * Connecting to MASTER 127.0.0.1:18504
12:55:39.888625 * MASTER <-> REPLICA sync started
12:55:39.888727 * REPLICAOF 127.0.0.1:18504 enabled (user request from 'id=4 
   addr=127.0.0.1:36164 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')
12:55:39.888884 * Non blocking connect for SYNC fired the event.
12:55:39.889106 * Master replied to PING, replication can continue...
12:55:39.889242 * Trying a partial resynchronization 
   (request bb412d2dd8fe6592b084a0921d92743af76bb408:1).
Master Log
12:55:39.889362 * Replica 127.0.0.1:18505 asks for synchronization
12:55:39.889412 * Partial resynchronization not accepted: 
   Replication ID mismatch (Replica asked for 'bb412d2dd8fe6592b084a0921d92743af76bb408', 
   my replication IDs are '4727e5c85a163b80fd81b1d32a27bc9e1d70d2cd' and 
   '0000000000000000000000000000000000000000')
12:55:39.889450 * Replication backlog created, 
   my new replication IDs are '1c71f9cfa5cfd7a50ab7a76888d079dea71da179' and 
   '0000000000000000000000000000000000000000'
12:55:39.889472 * Delay next BGSAVE for diskless SYNC
--- 다른 동기화 요청이 있을지 5초 동안 기다림 ---
12:55:44.928578 * Starting BGSAVE for SYNC with target: replicas sockets
Replica Log
12:55:44.928807 * Full resync from master: 1c71f9cfa5cfd7a50ab7a76888d079dea71da179:14
Master Log
12:55:44.942181 * Background RDB transfer started by pid 7526
7526:C 12:55:44.942353 * (Send(Start) EOF:9183d8d1d2950c95e00ad572404a54c2dbfaaf0f)
Replica Log
12:55:44.952917 * MASTER <-> REPLICA sync: receiving streamed RDB from master with EOF to parser
12:55:44.952955 * MASTER <-> REPLICA sync: Loading DB in memory
12:55:44.952984 * Loading RDB produced by version 7.0.8
12:55:44.952998 * RDB age 0 seconds
12:55:44.953012 * RDB memory usage when created 963.87 Mb
Master Log
--- Rdb 데이터를 복제본에 보내는데 5초 걸림 ---
7526:C 12:55:49.842008 * (Send(End) EOF:9183d8d1d2950c95e00ad572404a54c2dbfaaf0f)
7526:C 12:55:49.852363 * Fork CoW for RDB: current 0 MB, peak 0 MB, average 0 MB
12:55:49.859206 # Diskless rdb transfer, done reading from pipe, 1 replicas still up.
Replica Log
12:55:49.952858 * Done loading RDB, keys loaded: 9949010, keys expired: 0.
12:55:49.952911 * Discarding previously cached master state.
12:55:49.952929 * MASTER <-> REPLICA sync: Swapping active DB with loaded DB
12:55:49.952954 * MASTER <-> REPLICA sync: Discarding old DB in background
12:55:49.952981 * MASTER <-> REPLICA sync: Finished with success
12:55:49.953024 * (Send REPLCONF ACK 14)
Master Log
12:55:49.955488 * Background RDB transfer terminated with success
12:55:49.955509 * Streamed RDB transfer with replica 127.0.0.1:18505 succeeded (socket).
Waiting for REPLCONF ACK from slave to enable streaming
12:55:49.955551 * Synchronization with replica 127.0.0.1:18505 succeeded
12:55:49.975804 * (Received REPLCONF ACK 14)

자세한 흐름도

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

Full Sync Memory-Memory Full Sync Memory-Memory Full Sync Memory-Memory

로그

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초를 기다린다.

replicationCron() // 1초에 한번 실행
   replicationStartPendingFork() // 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 7526" 
   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 parser"
   "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 메모리가 사용되었음.
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
void readSyncBulkPayload(connection *conn)	replication.c
   While(1) loop를 돌면서 데이터를 받아서 메모리에 적재함. EOF를 만나면 loop를 종료함.
   "Done loading RDB, keys loaded: 9949010, keys expired: 0."
   replicationAttachToNewMaster() 	replication.c
      void replicationDiscardCachedMaster(void)	replication.c
         "Discarding previously cached master state."
   "MASTER <-> REPLICA sync: Swapping active DB with loaded DB"
   "MASTER <-> REPLICA sync: Discarding old DB in background"
   "MASTER <-> REPLICA sync: Finished with success"
   if (usemark) replicationSendAck();  -> REPLCONF ACK 
   if (server.aof_enabled) restartAOFAfterSYNC();
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
  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 Mem-to-Disk Functions >>

Email 返事がかかってなれば、メールでお知らせします。