Delete returns 0 for a key that exists

[monsterlane]

Seeing some really odd results using this extension with CodeIgniter's Redis session library. When close is called I get an error that it cannot free the lock. I'm using the latest release of this extension (2.2.7) and CI (3.0.6) on PHP 5.6.

Here's a link to the library's code: https://github.com/bcit-ci/CodeIgniter/blob/develop/system/libraries/Session/drivers/Session_redis_driver.php

Here's a modified code exert so you can see exactly where the error appears:

    protected function _release_lock($code = 0)
    {
        if (isset($this->_redis, $this->_lock_key) && $this->_lock)
        {
            $exists = $this->_redis->exists($this->_lock_key);
            $del = $this->_redis->delete($this->_lock_key);

            if ( !$del)
            {
                $exists2 = $this->_redis->exists($this->_lock_key);

                log_message('error', 'Session: Error while trying to free lock for '.$this->_lock_key . ', code=' . $code . ', del=' . var_export($del,true) . ', exists=' . var_export($exists,true) . ', exists2=' . var_export($exists2,true));
                return FALSE;
            }

            $this->_lock_key = NULL;
            $this->_lock = FALSE;
        }

        return TRUE;
    }

The error I get is:

Session: Error while trying to free lock for ci_session:guid:lock, code=2, del=0, exists=true, exists2=false

Is this expected since the key is set to expire? Why does exists return true but delete returns 0 immediately after? The second exists2 returns false as expected.

If this is expected, what is the proper way to delete the key so it returns a non 0 response?

[michael-grunder]

Hey,

Is it possible that the key is being removed by redis between your call to exists and del? When I run a simple test script against this sequence I get 1 for the del response.

It's always possible something else is happening, but just wanted to point out that it is theoretically possible for the key to get expired between those two round trips.

Mike

[monsterlane]

Hey @michael-grunder, I should also mention I usually see this error when I make two concurrent requests. Your analysis seems likely in that situation.

What's the proper way to handle this? I could do a delete and an exists where the !$del code is but that feels like the wrong approach.

[michael-grunder]

Perhaps a MULTI...EXEC block or a small piece of LUA script to make all the requests a single transaction?

[monsterlane]

This is part of a framework's session library and I don't think disallowing concurrent requests is the right direction. I'll pass your comments on to one of the developers thanks!

[michael-grunder]

It shouldn't disable concurrent connections really. Redis is already single-threaded, so when you get right down to it, only one del or exists call can get executed at the same time anyway. A small multi block or LUA script just makes sure that both commands execute atomically (avoiding race conditions).

Again, I don't know if that's actually what's causing the problem but it's just a guess!

Let me know if you get more info on the problem and I'll be happy to help!

[monsterlane]

Oh sorry what I meant by that is concurrent AJAX requests. This is part of a PHP framework and when two simultaneous AJAX calls are sent one of them produces this error.

I didn't realize multi was part of Redis, I'll pass that on as well.

[narfbg]

Hi, I'm the developer that this was supposedly relayed to ... only I've been subscribed to this issue the whole time.

The exists() call in question was added by @monsterlane for debugging purposes; the original code is here (link pointing to the faulty delete() call line): https://github.com/bcit-ci/CodeIgniter/blob/3.0.6/system/libraries/Session/drivers/Session_redis_driver.php#L387

It is faulty because (bar Redis just dropping it for no obvious reason) the key in question does certainly exist when delete() is called - no external process deletes it, and the call never happens unless it is known that it the current process (and not another one) has created the key.
The whole purpose of that key is to block concurrent processes from modifying the same data - they all wait until it expires or is explicitly deleted before doing anything else.

As for the expiry possibility - "extremely unlikely" would be an understatement, because the TTL is set to 300 seconds (5 minutes) and so far the issue has only been reproduced while processing concurrent AJAX requests - no such requests taking 5+ minutes to complete would go unnoticed.