Pubsub Subscription reconnects every 3 seconds

[rtunazzz]

Pubsub subscription disconnects and reconnects every 3 seconds, raising an i/o timeout error.

Expected Behavior

Work as intended, without raising any errors

Current Behavior

Disconnects from Redis & logs discarding bad PubSub connection: read tcp [::1]:50044->[::1]:6379: i/o timeout every 3 seconds.
Here are the logs from my redis server, running default configuration with verbose loglevel:

From what I noticed, everything works as expected when I downgrade to v8.

Steps to Reproduce

package main

import (
	"context"
	"log"

	"github.com/go-redis/redis/v9"
)

var ctx = context.Background()

func main() {
	rdb := redis.NewClient(&redis.Options{
		Addr:     "localhost:6379",
		Password: "", // no password set
		DB:       0,  // use default DB
	})

	// There is no error because go-redis automatically reconnects on error.
	pubsub := rdb.Subscribe(ctx, "test")
	// Close the subscription when we are done.
	defer pubsub.Close()

	// Wait for confirmation that subscription is created before publishing anything.
	_, err := pubsub.Receive(ctx)
	if err != nil {
		panic(err)
	}

	ch := pubsub.Channel()
	for {
		select {
		case <-ctx.Done():
			return
		case msg := <-ch:
			log.Println(msg)
		}
	}
}

Code above results in:

go run main.go
redis: 2022/07/01 18:03:54 pubsub.go:159: redis: discarding bad PubSub connection: read tcp [::1]:50222->[::1]:6379: i/o timeout
redis: 2022/07/01 18:03:57 pubsub.go:159: redis: discarding bad PubSub connection: read tcp [::1]:50223->[::1]:6379: i/o timeout

Context (Environment)

• MacOS Monterey 12.4 (I've also tested w docker on golang:1.18-alpine and got the same result)
• Golang version 1.18
• github.com/go-redis/redis/v9 v9.0.0-beta.1

[purinda]

Have the same issue.

redis: 2022/07/03 12:50:20 pubsub.go:159: redis: discarding bad PubSub connection: read tcp [::1]:58835->[::1]:6379: i/o timeout

[zhou-xinzi]

Getting the exact same thing - issue (as expected) resolved once i changed version from v9 back to v8

[steevehook]

The main thing I think at least needs some documentation when it comes to subscribing, especially when it comes to subscribing to keyevent keyspace events is

Make sure the client does not have a ReadTimeout (which by default is 3), it is especially tricky when Redis is in cluster mode, as you'll need to overwrite the client timeout before subscribing

cluster.ForEachMaster(ctx, func(ctx context.Context, client *redis.Client) error {
  client = client.WithTimeout(0)
  sub := client.Subscribe(ctx, "__keyevent@0__:expired")
  ...
}

Correct me if I'm wrong @vmihailenco

[itsatony]

same issue using the universal client (tested case is single instance).

changing the connection options to ReadTimeout:0 and WriteTimeout:0 doesn't do anything:
options := redis.UniversalOptions{ Addrs: rInfo.Addrs, DB: rInfo.Db, ReadTimeout: 0, WriteTimeout: 0, }

Also tested sending pubs every 1-second. Messages are received without a problem, reconnect happens nonetheless.

Tested with 9.0beta1 and 9.0beta2 and Redis-Server v7

[j178]

I think this is caused by #2060, I issued a new issue #2175 and submit a fix #2176

[monkey92t]

fix by #2176