build-your-own-redis icon indicating copy to clipboard operation
build-your-own-redis copied to clipboard

Misleading logs when reusing a connection

Open rohitpaulk opened this issue 1 year ago • 3 comments

When we reuse a connection to send multiple commands, we still emit logs like this:

$ redis-cli SET a b
$ redis-cli SET b c

This can be misleading, giving the impression that these commands will be sent by different connections.

Thanks to @rsalmei for pointing this out!

rohitpaulk avatar Feb 21 '24 17:02 rohitpaulk

Let's instead do this:

[client-1]: Sending command "SET a b"
[client-1]: Sending command "SET b c"

And let's name these prefixes in a way that make sense for the stage. For example, if it's a replica sending these commands, let's use [replica-1] as the prefix.

rohitpaulk avatar Feb 21 '24 17:02 rohitpaulk

That's great, thank you, Paul!

I wasn't expecting that three redis-cli commands would end up on a single connection. And I especially liked your suggestion of also adjusting the prefixes. In the logs below, replication-11 could be a single divider line, and the prefixes would always reflect the actual source, i.e., [x] y would mean "The action y was made by/originated from x".

Thanks again.

remote: [replication-11] Setting key foo to 123
remote: [replication-11] $ redis-cli SET foo 123
remote: [replication-11] Setting key bar to 456
remote: [replication-11] $ redis-cli SET bar 456
remote: [replication-11] Setting key baz to 789
remote: [replication-11] $ redis-cli SET baz 789
remote: [your_program] Received: Ok("*3\r\n$3\r\nSET\r\n$3\r\nfoo\r\n$3\r\n123\r\n*3\r\n$3\r\nSET\r\n$3\r\nbar\r\n$3\r\n456\r\n*3\r\n$3\r\nSET\r\n$3\r\nbaz\r\n$3\r\n789\r\n")
remote: [your_program] <- Failure("Array([BulkString(\"SET\"), BulkString(\"foo\"), BulkString(\"123\")]) remaining 62")

rsalmei avatar Feb 21 '24 17:02 rsalmei

We've decided to emulate redis-cli a bit more closely:

[client-1] $ redis-cli SET foo bar
[client-1] > SET bar 234

The first command will stay as-is, and every next command will be logged with > as the prefix instead.

rohitpaulk avatar Jun 07 '24 15:06 rohitpaulk

Updated logs:

remote: [tester::#NA2] Running tests for Stage #NA2 (Replication - WAIT with multiple commands)
remote: [tester::#NA2] $ ./spawn_redis_server.sh --port 6379
remote: [tester::#NA2] Creating replica: 1
remote: [your_program] Started Redis server @ 127.0.0.1:6379
remote: [tester::#NA2] replica-1: $ redis-cli PING
remote: [tester::#NA2] replica-1: > REPLCONF listening-port 6380
remote: [tester::#NA2] replica-1: > REPLCONF capa psync2
remote: [tester::#NA2] replica-1: > PSYNC ? -1

ryan-gang avatar Jun 12 '24 07:06 ryan-gang