Unable to Receive the GETACK command from Master Server

[nwokejij]

I’m stuck on Stage 21: Get ACK With No commands.

My problem is that I am unable to receive to consistently receive the FULLRESYNC command, the RDB File, and the GETACK command from the master. I have tried logging these commands from the master to the replica and I have noticed something interesting. Sometimes when I rerun the tester, I am able to log the FULLRESYNC command and the RDB File, other times I am able to log just the FULLRESYNC command (not the RDB File), and other times I am unable to receive any commands at all. I have never received the GETACK command, though. I suspect this has something to do with race conditions, but I can’t figure out how to resolve this issue. I also have noticed that these logs appear after the test fails for some reason, which makes me unable to send the appropriate replica response to the GETACK command.

Here are some examples of the logs I have been receiving:
This is an example of the replica receiving the FULLRESYNC command

This is an example of the log only receiving the buffer length and nothing else below that.

remote: Running tests on your code. Logs should appear shortly...
remote:
remote: [tester::#XV6] Running tests for Stage #XV6 (Replication - ACKs with no commands)
remote: [tester::#XV6] Master is running on port 6379
remote: [tester::#XV6] $ ./spawn_redis_server.sh --port 6380 --replicaof "localhost 6379"
remote: [your_program] Logs from your program will appear here!
remote: [tester::#XV6] master: Waiting for replica to initiate handshake with "PING" command
remote: [your_program] Connected to master
remote: [tester::#XV6] Received ["PING"]
remote: [tester::#XV6] master: Sent "PONG"
remote: [tester::#XV6] master: Waiting for replica to send "REPLCONF listening-port 6380" command
remote: [your_program] Buffer Length 7
remote: [your_program] Raw data received: +PONG
remote: [your_program]
remote: [your_program] Received message: +PONG
remote: [your_program] Parsed response: +PONG
remote: [your_program] End of data processing block
remote: [tester::#XV6] Received ["REPLCONF", "listening-port", "6380"]
remote: [tester::#XV6] master: Sent "OK"
remote: [tester::#XV6] master: Waiting for replica to send "REPLCONF capa" command
remote: [tester::#XV6] Received ["REPLCONF", "capa", "psync2"]
remote: [your_program] Buffer Length 5
remote: [your_program] Raw data received: +OK
remote: [your_program]
remote: [your_program] Received message: +OK
remote: [your_program] Parsed response: +OK
remote: [your_program] End of data processing block
remote: [tester::#XV6] master: Sent "OK"
remote: [tester::#XV6] master: Waiting for replica to send "PSYNC" command
remote: [tester::#XV6] Received ["PSYNC", "?", "-1"]
remote: [your_program] Buffer Length 5
remote: [your_program] Raw data received: +OK
remote: [your_program]
remote: [your_program] Received message: +OK
remote: [your_program] Parsed response: +OK
remote: [your_program] End of data processing block
remote: [tester::#XV6] master: Sent "FULLRESYNC 75cd7bc10c49047e0d163660f3b90625b1af31dc 0"
remote: [tester::#XV6] Sent RDB file.
remote: [tester::#XV6] master: > REPLCONF GETACK *
remote: [tester::#XV6] Expected command to be "replconf", got "psync"
remote: [tester::#XV6] Test failed (try setting 'debug: true' in your codecrafters.yml to see more details)
remote: [your_program] Buffer Length 148

And this is an example of logging both the FULLRESYNC command and the RDB File, but not the GETACK command.

remote: Running tests on your code. Logs should appear shortly...
remote:
remote: [tester::#XV6] Running tests for Stage #XV6 (Replication - ACKs with no commands)
remote: [tester::#XV6] Master is running on port 6379
remote: [tester::#XV6] $ ./spawn_redis_server.sh --port 6380 --replicaof "localhost 6379"
remote: [your_program] Logs from your program will appear here!
remote: [tester::#XV6] master: Waiting for replica to initiate handshake with "PING" command
remote: [your_program] Connected to master
remote: [tester::#XV6] Received ["PING"]
remote: [tester::#XV6] master: Sent "PONG"
remote: [tester::#XV6] master: Waiting for replica to send "REPLCONF listening-port 6380" command
remote: [your_program] Buffer Length 7
remote: [your_program] Raw data received: +PONG
remote: [your_program]
remote: [your_program] Received message: +PONG
remote: [your_program] Parsed response: +PONG
remote: [your_program] End of data processing block
remote: [tester::#XV6] Received ["REPLCONF", "listening-port", "6380"]
remote: [tester::#XV6] master: Sent "OK"
remote: [tester::#XV6] master: Waiting for replica to send "REPLCONF capa" command
remote: [tester::#XV6] Received ["REPLCONF", "capa", "psync2"]
remote: [your_program] Buffer Length 5
remote: [your_program] Raw data received: +OK
remote: [your_program]
remote: [your_program] Received message: +OK
remote: [your_program] Parsed response: +OK
remote: [your_program] End of data processing block
remote: [tester::#XV6] master: Sent "OK"
remote: [tester::#XV6] master: Waiting for replica to send "PSYNC" command
remote: [tester::#XV6] Received ["PSYNC", "?", "-1"]
remote: [your_program] Buffer Length 5
remote: [your_program] Raw data received: +OK
remote: [your_program]
remote: [your_program] Received message: +OK
remote: [your_program] Parsed response: +OK
remote: [your_program] End of data processing block
remote: [tester::#XV6] master: Sent "FULLRESYNC 75cd7bc10c49047e0d163660f3b90625b1af31dc 0"
remote: [tester::#XV6] Sent RDB file.
remote: [tester::#XV6] master: > REPLCONF GETACK *
remote: [tester::#XV6] Expected command to be "replconf", got "psync"
remote: [tester::#XV6] Test failed (try setting 'debug: true' in your codecrafters.yml to see more details)
remote: [your_program] Buffer Length 148
remote: [your_program] Raw data received: +FULLRESYNC 75cd7bc10c49047e0d163660f3b90625b1af31dc 0
remote: [your_program] $88
remote: [your_program] REDIS0011�       redis-ver7.2.0�
remote: [your_program] redis-bits�@�ctime��eused-mem°�

And here’s a snippet of my code:

const net = require("net");
const portIndex = process.argv.indexOf("--port");
const isSlave = process.argv.indexOf("--replicaof");
const PORT = portIndex != -1 ? process.argv[portIndex + 1] : 6379;
const replicas = [];
let masterPort = 0;

if (isSlave != -1) {
    masterPort = process.argv[isSlave + 1];
    masterPort = masterPort.split("localhost ")[1];
} else {
    masterPort = PORT;
}

const replicaDict = {};
let buffer = '';

const client = net.createConnection({ port: masterPort, host: 'localhost' }, () => {
    console.log('Connected to master');
    client.write("*1\r\n" + getBulkString("PING"));
});

client.on('data', (data) => {
    buffer += data.toString('utf8');
    console.log("Buffer Length", buffer.length);
    console.log('Raw data received:', buffer);
    if (buffer.indexOf("FULLRESYNC") != -1) {
        console.log("Reached This If/Else Block");
        // client.write("*3/r/n" + getBulkString("REPLCONF") + getBulkString("ACK")+ getBulkString("0")); //commented out the replica response
    }
    let messages = buffer.split('\r\n');
    let resData = buffer; // will use to handle the handshake responses
    buffer = messages.pop(); // resets the buffer with ""
    messages.forEach((message) => {
        console.log(`Received message: ${message.trim()}`);
        if (message.startsWith('> REPLCONF GETACK')) {
            console.log('Received REPLCONF GETACK');
            // Handle REPLCONF GETACK message
            // Never reaches this block
        }
    });

    if (resData) {
        const resp = resData.split('\r\n')[0];
        console.log('Parsed response:', resp);

        if (resp === "+PONG") {
            client.write("*3\r\n" + getBulkString("REPLCONF") + getBulkString("listening-port") + getBulkString(PORT));
            client.write("*3\r\n" + getBulkString("REPLCONF") + getBulkString("capa") + getBulkString("psync2")); 
        } else if (resp === "+OK") {
            client.write("*3\r\n" + getBulkString("PSYNC") + getBulkString("?") + getBulkString("-1")); 
        }
    }
    console.log("End of data processing block");
});

client.on('end', () => {
    console.log('Disconnected from master');
});

client.on('error', (err) => {
    if (err.code === 'EPIPE') {
        console.error('EPIPE error: attempting to write to a closed stream');
    } else {
        console.error('Connection error:', err);
    }
});

I have found this similar post describing a similar issue that I am having, but I am still unsure on how to implement the solution to that problem.

[rohitpaulk]

@nwokejij can you try enabling debug logs? How do I debug test failures? - CodeCrafters

That should give more insight into exactly what bytes are sent/received.

[nwokejij]

After tinkering around and looking at other solutions, I was at least able to consistently get the “+FULLRESYNC” command from the master. Since that was able to happen consistently, I just sent the “REPLCONF ACK 0” whenever the replica received that command and I was able to pass that stage. However, this problem ended up carrying over to the next stage. From the debug logs, it seems that the replica experiences a delay when receiving the commands from the master, beginning when the master first sends the FULLRESYNC command. Here are the logs that I am receiving (These have also been inconsistent as well):

And here is my updated code. I kept a buffer tracking variable (“offset”) to return the number of bytes for each command (the instructions for “ACKS with commands”)

const replicaDict = {};

const handleHandshake = (port) => {
    const client = net.createConnection({ host: "localhost", port: port }, () => {
      console.log("connected to master", "Port: ", port);
      client.write("*1\r\n$4\r\nPING\r\n");
      let firstAck = false;
      let offset = 0;
      let repl1 = false;
      client.on("data", (data) => {
        let message = Buffer.from(data).toString();
        let commands = message.split("\r\n");
        console.log(`Command recieved by replica:`, commands);
          if (commands[0] == "+PONG") {
            client.write("*3\r\n" + getBulkString("REPLCONF") + getBulkString("listening-port")+ getBulkString(PORT));
          } else if (commands[0] == "+OK") {
            if (repl1 == false) {
              client.write("*3\r\n" + getBulkString("REPLCONF") + getBulkString("capa") + getBulkString("psync2"));
              repl1 = true;
            } else client.write("*3\r\n" + getBulkString("PSYNC") + getBulkString("?")+ getBulkString("-1"));
          } else if (commands.includes("PING") ){
            if (firstAck){
                offset += message.length;
                console.log("Offset in Ping Block:" + offset);
                if (commands.includes("REPLCONF")){
                    client.write("*3\r\n" + getBulkString("REPLCONF") + getBulkString("ACK") + getBulkString(offset.toString()));
                }
                offset += 37; // length of REPLCONF GETACK command
            }
            
        }else if (commands.includes("REPLCONF") || commands[0].includes("+FULLRESYNC")) {
            client.write("*3\r\n" + getBulkString("REPLCONF") + getBulkString("ACK") + getBulkString(offset.toString()));
            firstAck = true;
            if (commands.includes("REPLCONF")){
                offset += 37;
            } 
            console.log("Offset IN REPLCONF Block: " + offset);
        }else { // for SET and GET commands received
            if (firstAck){
                offset += message.length;
                console.log("Offset in Else Block: "+ offset);
            }
            parseRedisResponseFromMaster(message, replicaDict);
          }
            })
          })
        }

const net = require("net");
const portIndex = process.argv.indexOf("--port");
const isSlave = process.argv.indexOf("--replicaof");
const PORT = portIndex != -1 ? process.argv[portIndex + 1] : 6379;
const replicas = [];
let masterPort = 0;

if (isSlave != -1) {
    masterPort = process.argv[isSlave + 1];
    masterPort = masterPort.split(" ")[1];
    handleHandshake(masterPort);
    console.log("Master Port:" + masterPort)
} else {
    masterPort = PORT;
}

[nwokejij]

Here are the rest of my logs. I wasn’t able to upload them all at once:

[nwokejij]

[nwokejij]

Ok I was able to fix my issue. I did two things: I used async/await to wait for all of the data to arrive, and I partitioned each RESP array so that each command could be processed individually.