Session: Error while trying to free lock for ci_session

This makes the error disappear but is probably not the way to solve it:

Code:

    protected function _release_lock()
    {
        if (isset($this->_redis, $this->_lock_key) && $this->_lock)
        {
            if ( ! $this->_redis->delete($this->_lock_key) && $this->_redis->exists($this->_lock_key))
            {
                log_message('error', 'Session: Error while trying to free lock for '.$this->_lock_key);
                return FALSE;
            }

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

        return TRUE;
    }

Yea, not logging the error in the first place is better than an exists() call ... but neither is ideal, I want to know for sure when and why delete() would return 0 fist.

I posed this as an issue on phpredis's Github page to see if I can get clarification on deleting keys set to expire: https://github.com/phpredis/phpredis/issues/816

Great, I've subscribed to the issue. But ... as somebody who deals with bug reports on a daily basis, I can tell you that's far from a good one. Here's why:

- "delete() returns 0 while deleting 1 key" is all you know for sure.
- The possibility of it returning 0 specifically for keys set to expire is ... a noteworthy detail, but your wording choice makes it rather a speculation.
- I can assure you, the phpredis maintainer(s) don't give a crap how you managed to encounter the behavior, linking to or even mentioning CodeIgniter is an unnecessary distraction.
- Linking to this thread (or a post in it) may be helpful to gain context, but using third-party resources to provide what should've been in the issue description is a major annoyance. I sometimes receive bug reports linking to StackOverflow questions "for the details" and I am infuriated when that happens - it's a lazy thing to do, not helping others to help you while asking them to do so.
- FFS, stop calling it "3.06", it's 3.0.6 and I've told you that previously ... how can you do that distinction for phpredis with 2.2.7 and then mess it up for CI in the very same sentence?

That last one is for me really, but yea ... when doing bug reports - leave out speculation and irrelevant details, focus on the substance.

Great, I've subscribed to the issue. But ... as somebody who deals with bug reports on a daily basis, I can tell you that's far from a good one. Here's why:

- "delete() returns 0 while deleting 1 key" is all you know for sure.
- The possibility of it returning 0 specifically for keys set to expire is ... a noteworthy detail, but your wording choice makes it rather a speculation.
- I can assure you, the phpredis maintainer(s) don't give a crap how you managed to encounter the behavior, linking to or even mentioning CodeIgniter is an unnecessary distraction.
- Linking to this thread (or a post in it) may be helpful to gain context, but using third-party resources to provide what should've been in the issue description is a major annoyance. I sometimes receive bug reports linking to StackOverflow questions "for the details" and I am infuriated when that happens - it's a lazy thing to do, not helping others to help you while asking them to do so.
- FFS, stop calling it "3.06", it's 3.0.6 and I've told you that previously ... how can you do that distinction for phpredis with 2.2.7 and then mess it up for CI in the very same sentence?

That last one is for me really, but yea ... when doing bug reports - leave out speculation and irrelevant details, focus on the substance.

Well you're quite the surly fellow today. I've updated the issue with code inline and a link to the library in case they need more detail.

Well you're quite the surly fellow today.

I just value my message being heard over political correctness. Every day.

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.

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).

It appears to be a concurrency issue when multiple requests are involved which makes sense as everyone reporting the issue is firing AJAX calls. Unless you want to add "concurrent AJAX calls are likely to cause session lock errors" to the session documentation it needs to be changed at the framework level.

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.

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).

It appears to be a concurrency issue when multiple requests are involved which makes sense as everyone reporting the issue is firing AJAX calls. Unless you want to add "concurrent AJAX calls are likely to cause session lock errors" to the session documentation it needs to be changed at the framework level.

This is a meaningless conclusion ...

This is a meaningless conclusion ...

What is supposed to happen in this scenario;

1. Two AJAX requests are fired (near) simultaneously
2. Both methods call session_write_close() as their first line of code (session library is autoloaded)
3. One of the two requests has to land first, it calls close and deletes the lock
4. Before the first call finishes it's logic the second request lands
5. The second request calls close, the lock doesn't exist as it was deleted by the first call?

2 is a bad decision in the first place.

5 cannot happen because request B session_start() will block until request A's session_write_close() is complete. This is THE sole purpose of locking.

2 is a bad decision in the first place.

It's necessary for performance as outlined in your documentation. None of the methods we call concurrently write session data. The library is auto-loaded for an auth check as our entire app is behind a login.

5 cannot happen because request B session_start() will block until request A's session_write_close() is complete. This is THE sole purpose of locking.

I have no idea what's going on then. Something isn't working properly if that scenario is supposed to be handled.

I have no idea what's going on then. Something isn't working properly if that scenario is supposed to be handled.

Exactly.

Hi, I'm trying to debug this strange issue.. I can reproduce it with many curl request parallelized with xargs -P, I can't figure out why sometimes a session lock is deleted while is used (when the wrong release occurs, the TTL on the lock key is -2).

A stupid workaround, while I'm digging into code is to randomize the time to wait in Session_redis_driver.php, line 340 instead of:

PHP Code:

sleep(1); 


replace with:

PHP Code:

$sleep_random = rand(100000,500000);
usleep(500000+$sleep_random); 


In this way I reduce a lot the "Error while trying to free lock.." occurence, before that i can reproduce the error with 8-12 concurrent request, now I have to raise up to 64 parallel request.

I hope it helps

k.