Redis Challenge Stage #YG4: only some set commands reach replica (Go)

I’m stuck on stage 13.

I’ve tried so I’ve set up two go routines to handle connections from clients and masters (for replicas). Issue is whenever I run the test, only some of the SET commands will propagate to the replicas. usually its second or third. but never all three. Not sure whats going on.

here’s a snippet of my code:
server.go: package mainimport ( "encoding/base64" "flag" "fmt" "io" "net" " - Pastebin.com

Here are my logs:

codecrafters test
Initiating test run...
 
⏳ Turbo test runners busy. You are in queue.
 
Upgrade to skip the wait: https://codecrafters.io/turbo
 
Running tests. Logs should appear shortly...
 
Debug = true
 
[replication-13] Running tests for Replication > Stage #13: Command Processing
[replication-13] Master is running on port 6379
[replication-13] $ ./spawn_redis_server.sh --port 6380 --replicaof localhost 6379
[replication-13] master: Received bytes: "*1\r\n$4\r\nPING\r\n"
[replication-13] master: Received RESP value: ["PING"]
[replication-13] Received ["PING"]
[replication-13] master: Sent "PONG"
[replication-13] master: Sent bytes: "+PONG\r\n"
[replication-13] master: Received bytes: "*3\r\n$8\r\nREPLCONF\r\n$14\r\nlistening-port\r\n$4\r\n6380\r\n"
[replication-13] master: Received RESP value: ["REPLCONF", "listening-port", "6380"]
[replication-13] Received ["REPLCONF", "listening-port", "6380"]
[replication-13] master: Sent "OK"
[replication-13] master: Sent bytes: "+OK\r\n"
[replication-13] master: Received bytes: "*3\r\n$8\r\nREPLCONF\r\n$4\r\ncapa\r\n$6\r\npsync2\r\n"
[replication-13] master: Received RESP value: ["REPLCONF", "capa", "psync2"]
[replication-13] Received ["REPLCONF", "capa", "psync2"]
[replication-13] master: Sent "OK"
[replication-13] master: Sent bytes: "+OK\r\n"
[replication-13] master: Received bytes: "*3\r\n$5\r\nPSYNC\r\n$1\r\n?\r\n$2\r\n-1\r\n"
[replication-13] master: Received RESP value: ["PSYNC", "?", "-1"]
[replication-13] Received ["PSYNC", "?", "-1"]
[your_program] Listening on port: 6380
[replication-13] master: Sent "FULLRESYNC 75cd7bc10c49047e0d163660f3b90625b1af31dc 0"
[replication-13] master: Sent bytes: "+FULLRESYNC 75cd7bc10c49047e0d163660f3b90625b1af31dc 0\r\n"
[replication-13] Sending RDB file...
[replication-13] master: Sent bytes: "$88\r\nREDIS0011\xfa\tredis-ver\x057.2.0\xfa\nredis-bits\xc0@\xfa\x05ctime\xc2m\b\xbce\xfa\bused-mem°\xc4\x10\x00\xfa\baof-base\xc0\x00\xff\xf0n;\xfe\xc0\xffZ\xa2"
[replication-13] Sent RDB file.
[your_program] Unknown type: +Client connected:  [::1]:6379
[your_program] Invalid request, expected array
[replication-13] master: $ redis-cli SET foo 123
[replication-13] master: Sent bytes: "*3\r\n$3\r\nSET\r\n$3\r\nfoo\r\n$3\r\n123\r\n"
[replication-13] master: $ redis-cli SET bar 456
[replication-13] master: Sent bytes: "*3\r\n$3\r\nSET\r\n$3\r\nbar\r\n$3\r\n456\r\n"
[replication-13] master: $ redis-cli SET baz 789
[replication-13] master: Sent bytes: "*3\r\n$3\r\nSET\r\n$3\r\nbaz\r\n$3\r\n789\r\n"
[replication-13] Getting key foo
[replication-13] client: $ redis-cli GET foo
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[your_program] Client connected:  [::1]:6379
[your_program] slave received: SET [{bulk  0 foo [] 0 false} {bulk  0 123 [] 0 false}] result: {string OK 0  [] 0 false}
[your_program] slave DB VALUE: map[foo:{string 123 0  [] 0 false}]
[your_program] Client connected:  [::1]:6379
[your_program] slave received: SET [{bulk  0 bar [] 0 false} {bulk  0 456 [] 0 false}] result: {string OK 0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {string 123 0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] client: Received bytes: "+123\r\n"
[replication-13] client: Received RESP value: "123"
[replication-13] Received "123"
[replication-13] Getting key bar
[replication-13] client: $ redis-cli GET bar
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbar\r\n"
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 bar [] 0 false}] result: {string 456 0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] client: Received bytes: "+456\r\n"
[replication-13] client: Received RESP value: "456"
[replication-13] Received "456"
[replication-13] Getting key baz
[replication-13] client: $ redis-cli GET baz
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbaz\r\n"
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 baz [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] client: Received bytes: "$-1\r\n"
[replication-13] client: Received RESP value: NIL
[replication-13] Retrying... (1/5 attempts)
[replication-13] client: $ redis-cli GET baz
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbaz\r\n"
[replication-13] client: Received bytes: "$-1\r\n"
[replication-13] client: Received RESP value: NIL
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 baz [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] Retrying... (2/5 attempts)
[replication-13] client: $ redis-cli GET baz
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbaz\r\n"
[replication-13] client: Received bytes: "$-1\r\n"
[replication-13] client: Received RESP value: NIL
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 baz [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] Retrying... (3/5 attempts)
[replication-13] client: $ redis-cli GET baz
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbaz\r\n"
[replication-13] client: Received bytes: "$-1\r\n"
[replication-13] client: Received RESP value: NIL
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 baz [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] Retrying... (4/5 attempts)
[replication-13] client: $ redis-cli GET baz
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbaz\r\n"
[replication-13] client: Received bytes: "$-1\r\n"
[replication-13] client: Received RESP value: NIL
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 baz [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[replication-13] Retrying... (5/5 attempts)
[replication-13] client: $ redis-cli GET baz
[replication-13] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nbaz\r\n"
[replication-13] client: Received bytes: "$-1\r\n"
[replication-13] client: Received RESP value: NIL
[your_program] Client connected:  [::1]:33970
[your_program] slave received: GET [{bulk  0 baz [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} foo:{string 123 0  [] 0 false}]
[your_program] Client disconnected:  [::1]:33970
[your_program] ERR IS read tcp [::1]:53302->[::1]:6379: read: connection reset by peer
[replication-13] Expected simple string or bulk string, got NIL
[replication-13] Test failed
[replication-13] Terminating program
[replication-13] Program terminated successfully

This part of the logs seems relevant - @Maniktherana could you try logging out what you received too, that isn’t an array? I think that’ll help shed some light on what’s going on.

updated logs: [replication-13] Sending RDB file...[replication-13] master: Sent bytes: "$8 - Pastebin.com

These are logs from when the replica is receving the RDB file. I’m not explicitly accepting the RDB file and its not quite an array, hence why its there. You can refer to line 40 in my code: GitHub - Maniktherana/tmp

if value.Typ != "array" {
			fmt.Println(kv.Info.Role, "Invalid request, expected array, got:", value)
			continue
		}

		if len(value.Array) == 0 {
			fmt.Println("Invalid request, expected array length > 0, got:" + fmt.Sprint(len(value.Array)))
			continue
		}

I don’t think this is related

EDIT: also note that this time bar and baz get saved but not foo. last time it was foo and bar. I’ll try to pretty print the resp values in my logs

@Maniktherana my best guess is that one of the commands is getting swallowed somewhere in parsing - could you confirm this by adding a log here? tmp/app/resp.go at 3fdc659ea21dec3891baf03acdf1776348371169 · Maniktherana/tmp · GitHub (soon after reading bytes from the reader).

@rohitpaulk added the log here:

func (r *Resp) readLine() (line []byte, n int, err error) {
	for {
		b, err := r.reader.ReadByte()
		if err != nil {
			return nil, 0, err
		}
+ 		fmt.Printf("%c", b)
		n += 1
		line = append(line, b)
		if len(line) >= 2 && line[len(line)-2] == '\r' {
			break
		}
	}
	return line[:len(line)-2], n, nil
}

logs:

[tester::#YG4] Sent RDB file.
[tester::#YG4] master: $ redis-cli SET foo 123
[tester::#YG4] master: Sent bytes: "*3\r\n$3\r\nSET\r\n$3\r\nfoo\r\n$3\r\n123\r\n"
[tester::#YG4] master: $ redis-cli SET bar 456
[tester::#YG4] master: Sent bytes: "*3\r\n$3\r\nSET\r\n$3\r\nbar\r\n$3\r\n456\r\n"
[tester::#YG4] master: $ redis-cli SET baz 789
[tester::#YG4] master: Sent bytes: "*3\r\n$3\r\nSET\r\n$3\r\nbaz\r\n$3\r\n789\r\n"
[tester::#YG4] Getting key foo
[tester::#YG4] client: $ redis-cli GET foo
[tester::#YG4] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[your_program] Unknown type: +Client connected:  [::1]:6379
[your_program] Invalid request, expected array
[your_program] 88
[your_program] *3
[your_program] Client connected:  [::1]:6379
[your_program] Invalid request, expected array
[your_program] 3
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:6379
[your_program] slave received: SET [{bulk  0 bar [] 0 false} {bulk  0 456 [] 0 false}] result: {string OK 0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false}]
[your_program] 3
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:6379
[your_program] slave received: SET [{bulk  0 baz [] 0 false} {bulk  0 789 [] 0 false}] result: {string OK 0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[your_program] 2
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:46856
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[tester::#YG4] client: Received bytes: "$-1\r\n"
[tester::#YG4] client: Received RESP value: NIL
[tester::#YG4] Retrying... (1/5 attempts)
[tester::#YG4] client: $ redis-cli GET foo
[tester::#YG4] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[your_program] 2
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:46856
[tester::#YG4] client: Received bytes: "$-1\r\n"
[tester::#YG4] client: Received RESP value: NIL
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[tester::#YG4] Retrying... (2/5 attempts)
[tester::#YG4] client: $ redis-cli GET foo
[tester::#YG4] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[tester::#YG4] client: Received bytes: "$-1\r\n"
[tester::#YG4] client: Received RESP value: NIL
[your_program] 2
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:46856
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[tester::#YG4] Retrying... (3/5 attempts)
[tester::#YG4] client: $ redis-cli GET foo
[tester::#YG4] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[your_program] 2
[your_program] 3
[your_program] 
[your_program] 3
[tester::#YG4] client: Received bytes: "$-1\r\n"
[tester::#YG4] client: Received RESP value: NIL
[your_program] 
[your_program] Client connected:  [::1]:46856
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[tester::#YG4] Retrying... (4/5 attempts)
[tester::#YG4] client: $ redis-cli GET foo
[tester::#YG4] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[your_program] 2
[your_program] 3
[tester::#YG4] client: Received bytes: "$-1\r\n"
[tester::#YG4] client: Received RESP value: NIL
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:46856
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[tester::#YG4] Retrying... (5/5 attempts)
[tester::#YG4] client: $ redis-cli GET foo
[tester::#YG4] client: Sent bytes: "*2\r\n$3\r\nGET\r\n$3\r\nfoo\r\n"
[tester::#YG4] client: Received bytes: "$-1\r\n"
[tester::#YG4] client: Received RESP value: NIL
[your_program] 2
[your_program] 3
[your_program] 
[your_program] 3
[your_program] 
[your_program] Client connected:  [::1]:46856
[your_program] slave received: GET [{bulk  0 foo [] 0 false}] result: {null  0  [] 0 false}
[your_program] slave DB VALUE: map[bar:{string 456 0  [] 0 false} baz:{string 789 0  [] 0 false}]
[tester::#YG4] Expected simple string or bulk string, got NIL
[tester::#YG4] Test failed
[tester::#YG4] Terminating program
[your_program] Client disconnected:  [::1]:46856
[your_program] ERR IS read tcp [::1]:33742->[::1]:6379: read: connection reset by peer
[tester::#YG4] Program terminated successfully

is the issue here in the parsing or could it be possible that its not even receiving the request?

Note: I’ve updated the title of this post to include the stage ID (#YC4). You can learn about the stages rename here: Upcoming change: Stages overhaul.

@Maniktherana something seems weird with the logging here, I only see numbers printed and no content? More bytes are certainly being received since I see the parsed version in “slave received”. Could you try logging in such a way that every single byte received is logged out? Without that it’s hard to tell whether this is a parsing issue or a timing/concurrency issue.