Poor performance of session.UpdateExpiration on 200 thousands+ keys with new radix lib

[r3eg]

Hello Makis!

I have more 200 thousands key in redis on prod server and found that after upgrading iris on v11 from redigo to radix lib that I have problems with perfomance when calling session.UpdateExpiration method (it`s executing minimum 10 seconds on a powerful prod server and more than 30 seconds on usual local).

While debugging I found place where freezes, it`s here:

func (r *Service) UpdateTTLMany(prefix string, newSecondsLifeTime int64) error {
	keys, err := r.getKeys(prefix)
	if err != nil {
		return err
	}
...
}

and inside getKeys here:

scanner := radix.NewScanner(r.pool, radix.ScanOpts{
		Command: "SCAN",
		Pattern: r.Config.Prefix + prefix + r.Config.Delim + "*", // get all of this session except its root sid.
		//	Count: 9999999999,
	})

	var key string
	for scanner.Next(&key) {
		keys = append(keys, key)
	}

Just has watched old v10 iris and old method getKeysConn did not cause such delay ...

func (r *Service) getKeysConn(c redis.Conn, prefix string) ([]string, error) {
	if err := c.Send("SCAN", 0, "MATCH", r.Config.Prefix+prefix+"*", "COUNT", 9999999999); err != nil {
		return nil, err
	}

	if err := c.Flush(); err != nil {
		return nil, err
	}

	reply, err := c.Receive()
	if err != nil || reply == nil {
		return nil, err
	}

Maybe reason in difference between old and new scan commands? Could you help?

[kataras]

No there is no difference in the commands themselves. Bbecause underline the radix library adds a MATCH too as I can remember, that's why I omit it:

	args = append(args, cursor)
	if o.Pattern != "" {
		args = append(args, "MATCH", o.Pattern)
	}

Ref: https://github.com/mediocregopher/radix/blob/1594fa6fbca09c298ed1379f6a6a3b39fba45fd1/scanner.go#L50-L53

The only difference between versions is the library replacement, I am thinking if we should provide an option for both of these libraries? @r3eg

[r3eg]

@kataras Yes, I saw MATCH command in radix lib, but just now I executed the same command (search by sid_* pattern) in Redis Desktop Manager and this command executed instantly, but 30 seconds+ in getKeys method...

[kataras]

Can you test to run using the older version of redis(just copy-paste the old sessiondb/redis files and make some changes on the configuration)? Maybe the problem is on unmarshal

[r3eg]

@kataras this cycle is executed several seconds on each key inside radix lib

func (s *scanner) Next(res *string) bool {
	for {
		if s.err != nil {
			return false
		}

		for s.resIdx < len(s.res.keys) {
			*res = s.res.keys[s.resIdx]
			s.resIdx++
			if *res != "" {
				return true
			}
		}

		if s.res.cur == "0" && s.res.keys != nil {
			return false
		}

		s.err = s.Client.Do(s.cmd(&s.res, s.res.cur))
		s.resIdx = 0
	}
}

[r3eg]

@kataras Makis, I have tested get keys on old redis module (just copy-paste it in service.go) and it works instantly. This is the part of code:

func (r *Service) UpdateTTLMany(prefix string, newSecondsLifeTime int64) error {
	c := r.pool.Get()
	defer c.Close()
	if err := c.Err(); err != nil {
		return err
	}

	keys, err := r.getKeysConn(c, prefix)
	if err != nil {
		return err
	}

getKeysConn does the same but no delay at all...

[kataras]

I see, so the previously used redigo library is faster here (although the radix one is faster on pub sub used on neffos).

OK, so I will revert it and get back to the redigo one.

Sounds good?

[r3eg]

@kataras Yes, sounds good (it is advisable to maintain compatibility with new modules as much as possible) I have nothing against radix, but this problem immediately got out on prod server. It might be worth using the optional redigo or radix depending on your specific goals.

[kataras]

Yes, it will be like config.Driver = Redigo, Radix. Also there is another redis go client but I've never tested its performance and stability: https://github.com/go-redis/redis , so for now we will not support it unless it's requested.

[r3eg]

@kataras Yes, it will be a good solution with config.Driver

[kataras]

Yes, it will default to 'redigo' though but without any breaking changes and this gives us the chance to support more redis clients in the future without the requirement of a, whole, new sessiondb for the same backend service (redis).

[r3eg]

@kataras Ok Makis! Thank you for fast support!

[kataras]

I thank YOU @r3eg, always!

It's done. Could you please test it before I push the v11.2.4 which has some other fixes and a new feature too?

go get github.com/kataras/iris@master

iris/_examples/sessions/database/redis/main.go

Lines 16 to 33 in 7f64919

	db := redis.New(redis.Config{
	Network: "tcp",
	Addr: "127.0.0.1:6379",
	Timeout: time.Duration(30) * time.Second,
	MaxActive: 10,
	Password: "",
	Database: "",
	Prefix: "",
	Delim: "-",
	Driver: redis.Redigo(), // redis.Radix() can be used instead.
	})
	// optionally configure the underline driver:
	// driver := redis.Redigo()
	// driver.MaxIdle = ...
	// driver.IdleTimeout = ...
	// driver.Wait = ...
	// redis.Config {Driver: driver}

Defaults to Driver: Redigo()

[r3eg]

@kataras Thanks again Makis! Just tested now, seems to works fine. Tomorrow will be more complicated testing, but now I have no problem with compatibility, so just pulled your commit and now it works instantly!

[kataras]

You are welcome @r3eg, it was a good report and you helped me a lot, so many thanks to you, you did actually fix that issue not me :) We'll wait until tomorrow then, no problem!

[r3eg]

@kataras Hello Makis! Today I pushed changes to prod server, all works fine now, no problem with perfomance at all! Thank you again!

[kataras]

@r3eg that's nice!

I think I found the issue on radix, it is calling a new scan command based on the returned cursor from the SCAN redis command, which is the cursor. This is the problem: by default the COUNT is 10, we didn't provide a COUNT option on the radix implementation, while in the redigo one we have a COUNT of 9999999999 so it did fired one command to fetch your keys, and radix did 20000 commands to fetch 200 thousand keys. This is fixed now.

[majidbigdeli]

@r3eg that's nice!

I think I found the issue on radix, it is calling a new scan command based on the returned cursor from the SCAN redis command, which is the cursor. This is the problem: by default the COUNT is 10, we didn't provide a COUNT option on the radix implementation, while in the redigo one we have a COUNT of 9999999999 so it did fired one command to fetch your keys, and radix did 20000 commands to fetch 200 thousand keys. This is fixed now.

yes it is true . Bravo. Good point
Thank You @kataras .

[kataras]

Yeah, I pushed the commit. The COUNT is 300 thousand and it iterates until cursor returned by redis is 0 (when iteration is done/ it's full iter) I also added an improvement on the redigo driver one (before it was limited to nine billion nine hundred ninety nine million nine hundred ninety nine thousand nine hundred ninety nine).