Bug Report: "ERR CLIENT CACHING YES" Error in Rueidis Client Broadcast Mode

[dannotripp]

Bug: "ERR CLIENT CACHING YES" Error in Rueidis Broadcast Mode

Description

When using the rueidis client in Broadcast mode, the Redis server responds with the following error:

ERR CLIENT CACHING YES is only valid when tracking is enabled in OPTIN mode.

The rueidis client continues to work correctly and does not detect this error. However, the error count in INFO ERRORSTATS increases, which affects monitoring dashboards.

Steps to Reproduce

1. Use the rueidis client (v1.0.55) in Broadcast mode with Redis (v7.4.2 or v7.2.7).
2. Run the following code example:

// example code to reproduce the error
package main

import (
	"context"
	"log"
	"fmt"
	"time"

	"github.com/redis/rueidis"
)

func main() {
	myKey := "ab:ct:1"
	myValue := "This is but a simple value."

	client, err := rueidis.NewClient(rueidis.ClientOption{
		InitAddress: []string{"localhost:6379"}, // Redis host and port
		ClientTrackingOptions: []string{"PREFIX", myKey[:3], "BCAST"}, 
		ForceSingleClient: true,
	})

	if err != nil {
		log.Fatal(err)
	}
	defer client.Close()

	// Turn off client tracking
	// _ = client.Do(context.TODO(), client.B().ClientTracking().Off().Build())
	// Turn on client tracking with broadcast options
	// _ = client.Do(context.TODO(), client.B().ClientTracking().On().Prefix().Prefix(myKey[:3]).Bcast().Build())

	result := client.Do(context.TODO(), client.B().Set().Key(myKey).Value(myValue).Build())
	if err := result.Error(); err != nil {
		panic(fmt.Errorf("error setting key: %w", err))
	}

	result = client.DoCache(context.TODO(), client.B().Get().Key(myKey).Cache(), time.Hour)
	if err := result.Error(); err != nil {
		panic(fmt.Errorf("error getting key: %w", err))
	}

	result = client.DoCache(context.TODO(), client.B().Get().Key(myKey).Cache(), time.Hour)
	if err := result.Error(); err != nil {
		panic(fmt.Errorf("error getting key: %w", err))
	}
}

3. Capture Redis traffic using tcpdump:

   sudo tcpdump -i lo0 -X port 6379
   

4. Observe the error in the TCP traffic:

Selection from TCP Dump Output:

15:13:02.658203 IP6 localhost.59022 > localhost.6379: Flags [P.], seq 1:203, ack 1, 
win 6371, options [nop,nop,TS val 4271264530 ecr 3420375095], length 202: RESP 
"HELLO" "3" "CLIENT" "TRACKING" "ON" "PREFIX" "ab:" "BCAST" "CLIENT" "SETINFO" 
"LIB-NAME" "rueidis" "CLIENT" "SETINFO" "LIB-VER" "1.0.55"

15:13:02.658317 IP6 localhost.6379 > localhost.59022: Flags [P.], seq 1:160, ack 203, 
win 6368, options [nop,nop,TS val 3420375095 ecr 4271264530], length 159: RESP 
"%7" "server" "redis" "version" "7.4.2" "proto" "3" "id" "4" "mode" "standalone" 
"role" "master" "modules" empty "OK" "OK" "OK"

15:13:02.659592 IP6 localhost.59023 > localhost.6379: Flags [P.], seq 203:263, ack 
160, win 6369, options [nop,nop,TS val 3152557322 ecr 3962622008], length 60: RESP 
"SET" "ab:ct:1" "This is but a simple value."

15:13:02.659667 IP6 localhost.6379 > localhost.59022: Flags [P.], seq 160:198, ack 
203, win 6368, options [nop,nop,TS val 3420375096 ecr 4271264530], length 38: RESP 
">2" "invalidate" "ab:ct:1"

15:13:02.659674 IP6 localhost.6379 > localhost.59023: Flags [P.], seq 160:203, ack 
263, win 6367, options [nop,nop,TS val 3962622008 ecr 3152557322], length 43: RESP 
"OK" ">2" "invalidate" "ab:ct:1"

15:13:02.661129 IP6 localhost.59024 > localhost.6379: Flags [P.], seq 203:323, ack 
160, win 6369, options [nop,nop,TS val 1765149618 ecr 1117739839], length 120: RESP 
"CLIENT" "CACHING" "YES" "MULTI" "PTTL" "ab:ct:1" "GET" "ab:ct:1" "EXEC"

15:13:02.661183 IP6 localhost.6379 > localhost.59024: Flags [P.], seq 160:305, ack 
323, win 6366, options [nop,nop,TS val 1117739839 ecr 1765149618], length 145: RESP 
"ERR CLIENT CACHING YES is only valid when tracking is enabled in OPTIN mode." "OK" 
"QUEUED" "QUEUED" "-1" "This is but a simple value."

5. Run INFO ERRORSTATS in Redis and note that the error count increases which each run of the sample code.

redis-cli info errorstats

Info Errorstats Output:

# Errorstats
errorstat_ERR:count=2

Expected Behavior

• The rueidis client should function without triggering the above error on the server side.

Actual Behavior

• The rueidis client continues to function correctly.
• The Redis server returns the ERR CLIENT CACHING YES error in responses.
• The error can be observed in TCP traffic but is not surfaced by rueidis.
• The Redis INFO ERRORSTATS count increases.

Environment

• Rueidis Version: v1.0.55
• Redis Version: v7.4.2 / v7.2.7
• Operating System: macOS Sequoia 15.3.1

Potential Workaround

• In this code snippet, we initialize the rueidis client without ClientTrackingOptions, resulting in the client being created in default (OPTIN) mode.
• We issue commands to do the following:
• • Turn off client tracking
• • Reenable client tracking in Broadcast (BCAST) mode
• This results in the expected behavior with no ERR CLIENT CACHING YES error on the server side.

Steps to Reproduce

1. Use the rueidis client (v1.0.55) in Broadcast mode with Redis (v7.4.2 or v7.2.7).
2. Run the following code example:

// example of potential workaround for the error
package main

import (
	"context"
	"log"
	"fmt"
	"time"

	"github.com/redis/rueidis"
)

func main() {
	myKey := "ab:ct:1"
	myValue := "This is but a simple value."

	client, err := rueidis.NewClient(rueidis.ClientOption{
		InitAddress: []string{"localhost:6379"}, // Redis host and port
		// ClientTrackingOptions: []string{"PREFIX", myKey[:3], "BCAST"},  // Do not use ClientTrackingOptions to initialize rueidis client
		ForceSingleClient: true,
	})

	if err != nil {
		log.Fatal(err)
	}
	defer client.Close()

	// Turn off client tracking manually
	_ = client.Do(context.TODO(), client.B().ClientTracking().Off().Build())
	// Turn on client tracking with broadcast options
	_ = client.Do(context.TODO(), client.B().ClientTracking().On().Prefix().Prefix(myKey[:3]).Bcast().Build())

	result := client.Do(context.TODO(), client.B().Set().Key(myKey).Value(myValue).Build())
	if err := result.Error(); err != nil {
		panic(fmt.Errorf("error setting key: %w", err))
	}

	result = client.DoCache(context.TODO(), client.B().Get().Key(myKey).Cache(), time.Hour)
	if err := result.Error(); err != nil {
		panic(fmt.Errorf("error getting key: %w", err))
	}

	result = client.DoCache(context.TODO(), client.B().Get().Key(myKey).Cache(), time.Hour)
	if err := result.Error(); err != nil {
		panic(fmt.Errorf("error getting key: %w", err))
	}
}

3. Capture Redis traffic using tcpdump:

   sudo tcpdump -i lo0 -X port 6379
   

4. Observe the error in the TCP traffic:

** Selection from TCP Dump Output:**

17:11:37.628957 IP6 localhost.50009 > localhost.6379: Flags [P.], seq 1:182, ack 1,
win 6371, options [nop,nop,TS val 3558366321 ecr 1130411450], length 181: RESP
"HELLO" "3" "CLIENT" "TRACKING" "ON" "OPTIN" "CLIENT" "SETINFO" "LIB-NAME"
"rueidis" "CLIENT" "SETINFO" "LIB-VER" "1.0.55"

17:11:37.629079 IP6 localhost.6379 > localhost.50009: Flags [P.], seq 1:160, ack 182,
win 6369, options [nop,nop,TS val 1130411450 ecr 3558366321], length 159: RESP "%7"
"server" "redis" "version" "7.4.2" "proto" "3" "id" "9" "mode" "standalone" "role"
"master" "modules" empty "OK" "OK" "OK"

17:11:37.629197 IP6 localhost.50009 > localhost.6379: Flags [P.], seq 182:221, ack 160,
win 6369, options [nop,nop,TS val 3558366321 ecr 1130411450], length 39: RESP
"CLIENT" "TRACKING" "OFF"

17:11:37.629265 IP6 localhost.6379 > localhost.50009: Flags [P.], seq 160:165, ack 221,
win 6368, options [nop,nop,TS val 1130411450 ecr 3558366321], length 5: RESP "OK"

17:11:37.629333 IP6 localhost.50009 > localhost.6379: Flags [P.], seq 221:291, ack 165,
win 6369, options [nop,nop,TS val 3558366322 ecr 1130411450], length 70: RESP
"CLIENT" "TRACKING" "ON" "PREFIX" "ab:" "BCAST"

17:11:37.629399 IP6 localhost.6379 > localhost.50009: Flags [P.], seq 165:170, ack 291,
win 6367, options [nop,nop,TS val 1130411451 ecr 3558366322], length 5: RESP "OK"

17:11:37.629481 IP6 localhost.50009 > localhost.6379: Flags [P.], seq 291:351, ack 170,
win 6369, options [nop,nop,TS val 3558366322 ecr 1130411451], length 60: RESP "SET"
"ab:ct:1" "This is but a simple value."

17:11:37.629553 IP6 localhost.6379 > localhost.50009: Flags [P.], seq 170:213, ack 351,
win 6366, options [nop,nop,TS val 1130411451 ecr 3558366322], length 43: RESP "OK"
">2" "invalidate" "ab:ct:1"

17:11:37.630637 IP6 localhost.50010 > localhost.6379: Flags [P.], seq 182:302, ack 161,
win 6369, options [nop,nop,TS val 3781709923 ecr 2170916844], length 120: RESP
"CLIENT" "CACHING" "YES" "MULTI" "PTTL" "ab:ct:1" "GET" "ab:ct:1" "EXEC"

17:11:37.630730 IP6 localhost.6379 > localhost.50010: Flags [P.], seq 161:232, ack 302,
win 6367, options [nop,nop,TS val 2170916844 ecr 3781709923], length 71: RESP "OK"
"OK" "QUEUED" "QUEUED" "-1" "This is but a simple value."

5. Run INFO ERRORSTATS in Redis-cli and note that the error count does not increase with the above code sample.

redis-cli info errorstats

Info Errorstats Output:

# Errorstats
errorstat_ERR:count=2

Questions

• Is this a known issue?
• Am I instantiating the rueidis client incorrectly in the above code sample?