How to reproduce and resolve PHP Session Failures

In this article, we will take a look the PHP Session Hang issue. We will try to why it happens and how to solve this problem. If you are already familiar with this issue, you may skip directly to the conclusion at the bottom of this article. First, we will start by trying to reproduce the session hang problem.

When Session is not used

Write the following PHP Script.

<?php
    function useful_function() {
        sleep(1);
    }
    useful_function();
?>

Then, use the ab command to send 10 simultaneous requests to the server.

ab -c 10 -n 10 http://localhost:8999/first.php

The result should look similar to the following:

...
Concurrency Level:      10
Time taken for tests:   1.003 seconds
Complete requests:      10
...

Since we have sent 10 simultaneous requests per second, the execution time of the above command is of course 1 second.

Using PHP Session

Now let us add a function to show the number of page visits using PHP Session.

<?php //session_test1.php
    function useful_function(){
        sleep(1);
    }
    session_start();
    if(isset($_SESSION['visit_count'])===FALSE){
        $_SESSION['visit_count'] = 1;
    }
    else{
        $_SESSION['visit_count'] += 1;
    }
    $visit_count = 'visit_count = '.$_SESSION['visit_count'];
    echo $visit_count;
    aries_add_message_profile($visit_count); //add 'visit_count' to jennifer profiles
    useful_function();
?>

Sending a single request via curl, the result would look like the following:

curl -v http://localhost:8999/session_test1.php
*   Trying 127.0.0.1...
...
< HTTP/1.1 200 OK
< Date: Wed, 05 Dec 2018 05:34:53 GMT
< Server: Apache/2.2.22 (Ubuntu)
< Set-Cookie: PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7; expires=Wed, 05-Dec-2018 13:34:53 GMT; path=/
< Expires: Thu, 19 Nov 1981 08:52:00 GMT
...
visit_count = 1%  

In the response body, we can see that the visit count is 1 (visit_count=1). Since the PHPSESSID has been added to the HTTP response cookie, the PHP default session handler uses a cookie, and the PHPSESSID cookie value is used as the Session Identifier.

Let us send another request with curl, this time we will add PHPSESSID in the cookie

curl --cookie "PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7" http://localhost:8999/session_test1.php
...
visit_count = 2%  

This time we can see that the visit_count=2. So our newly added page visit feature is functioning properly.

Let us see what happen at the web server. If you list the contents of the /tmp directory, you will see that the lmrfd… file exists. If you inspect the file’s content, you will see how the session is saved:

visit_count|i:2;

PHP Session Failure Case 1

Let us send 10 simultaneous requests again using the ab command, this time we will specify the PHPSESSID as the cookie. The result of the command will look like the following:

ab -c 10 -n 10 -C PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7 http://localhost:8999/session_test1.php
...
Concurrency Level:      10
Time taken for tests:   10.006 seconds
Complete requests:      10
...

You can immediately notice that when we did not use the Session function, the execution time of the ab command was 1 second. However, after using the session, the same 10 requests took 10 seconds. JENNIFER X-View shows the following patterns.

The X-View plots the request time on the X-axis and the response time on the Y-axis. We can see that all 10 requests came at the same time, but the processing time is different.

If we inspect the transactions details, we can see that the start time is the same for the 10 requests, 16:12:52. However, the response time is 1 second, 2 seconds, 3 seconds … 10 seconds for each of the 10 requests respectively. Additionally, the session_start function of the last processed request took 9 seconds to execute. This is because the file session handler locks the session file to avoid race condition. (Note that the currently running function is flock used to obtain a lock.)

PHP Session Failure Case 2

Let’s make the problem a bit more serious. Suppose we updated our useful_function added a database connection for that function.

<?php //session_test2.php
    function useful_function($db){
        sleep(1);
    }
    $db = mysql_connect('...');
    session_start();
    if(isset($_SESSION['visit_count'])===FALSE){
        $_SESSION['visit_count'] = 1;
    }
    else{
        $_SESSION['visit_count'] += 1;
    }
    $visit_count = 'visit_count = '.$_SESSION['visit_count'];
    echo $visit_count;
    aries_add_message_profile($visit_count); 
    useful_function($db);
?>

mysql_connect was called before session_start (). In this case, if the request of one Session is called N times at the same time, the DB Connection number also increases by N. To avoid this, you should not acquire resources before session_start.

When you modify the code to get DB resources after calling session_start (), the Active DB Connection chart looks like this: Notice that the number of DB connections is kept at 1.

Troubleshooting with session_write_close

PHP.net warn of the above problem and suggests the following solutions.

1. Use the session_start function with the read_and_close option (This option is available only for PHP 7.0 and later.)
2. After modifying the session data, use session_commit or session_write_close to release session lock as soon as possible.

We will try to solve the problem by taking the second method.

<?php
    function useful_function($db){
        sleep(1);
    }
    session_start();
    if(isset($_SESSION['visit_count'])===FALSE){
        $_SESSION['visit_count'] = 1;
    }
    else{
        $_SESSION['visit_count'] += 1;
    }
    session_write_close(); //release session lock
    $visit_count = 'visit_count = '.$_SESSION['visit_count'];
    echo $visit_count;
    $db=mysql_connect('...'); 
    aries_add_message_profile($visit_count); 
    
    //Change _SESSION['visit_count']
    $_SESSION['visit_count'] = 'write data after session_write_close()'; 
    aries_add_message_profile($_SESSION['visit_count']); 
    useful_function($db);
?>

After modifying the code, as shown above, we will send 10 requests at the same time again.

ab -c 10 -n 10 -C PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7 http://localhost:8999/session_test3.php
...
Concurrency Level:      10
Time taken for tests:   1.007 seconds
...

The problem is resolved. All requests were processed at the same time. However, one must be cautious. The above code has modified $_SESSION [‘visit_count’] after session_write_close () call. How does it work? Let’s check out the Jennifer profile.

$_SESSION[‘visit_count’] value is ‘write data after session_write_close()’. You can see that it has been modified by. Now let’s examine the contents of the sess file stored in /tmp directory.

cat /tmp/sess_lmrfduhgfm6oik62fi2c9q4ek7 
visit_count|i:40;

You can see that the visit_count value is 40 instead of ‘write data after session_write_close ()‘. This means that the value of the $_SESSION variable modified since the call is valid for the duration of the request, but is not recorded in the Session data. This is a disadvantage of the session_write_close solution. If you modify the session and the code you are using is spread over several places, it is difficult to apply this method. If you make a mistake, the value you see and the value stored in the actual Session may be different.

Troubleshooting with Redis Session Handler

This time, we will use the Redis session handler that does not lock the Session to solve the problem. (You can also use Lock as an option.) Call session_test2.php (a script that does not use session_write_close) defined above 10 times at the same time.

ab -c 10 -n 10 -C PHPSESSID=lmrfduhgfm6oik62fi2c9q4ek7 http://localhost:8999/session_test2.php
...
Concurrency Level:      10
Time taken for tests:   1.006 seconds

The problem with Lock has disappeared. All requests were processed at the same time. Also, check the Session Data.

# redis-cli
127.0.0.1:6379> KEYS *
1) "PHPREDIS_SESSION:lmrfduhgfm6oik62fi2c9q4ek7"
127.0.0.1:6379> GET "PHPREDIS_SESSION:lmrfduhgfm6oik62fi2c9q4ek7"
"visit_count|i:6;"
127.0.0.1:6379> 

visit_count is recorded as 6 instead of 10. You have not had a lock and a concurrency problem has occurred. This is a disadvantage of session handlers that do not use locks. If you decide to use the Redis Session Handler without locking, you should be aware of this and do not expect that the value stored in the Session will be intact. The data that requires integrity should not be stored in the Session.

Framework, Library is not a solution

The above is a profile that can be checked when a database is specified as a session handler in CodeIgniter. Checking the SQL Query shows that you are using Lock and that the session_start () method call took more than 2 seconds, which indicates that the lock is causing the problem. The CodeIgniter Controller code used to reproduce the above is shown below.

<?php
class Welcome extends CI_Controller {
	function __construct(){
		parent::__construct();
		$this->load->library('session');
	}
	public function index()
	{
		sleep(1);
		$this->load->view('welcome_message');
	}
}

The code might look simple. However, this session_start and session_write_close is somewhat hidden.

If you are using CodeIgniter Session, please read CodeIgniter/A note about concurrency. You can assume that CodeIgniter has had a lot of trouble with Session Lock. (The CodeIgniter 3.0 Session Library is said to have been completely rewritten.) At that point, CodeIgniter says,

Locking is not the issue, it is a solution. Your issue is that you still have the session open, while you’ve already processed it and therefore no longer need it. So, what you need is to close the session for the current request after you no longer need it.

CodeIgniter – A note about concurrency

The above quote is from CodeIgniter’s view of Session Lock. Laravel’s Session function, on the other hand, does not use session_start and session locks. However, this causes a concurrency problem. Please take a look at this issue.

If you are using the session functionality of the framework, or library, you need to know about session locking. If you lock, you should unlock it as soon as possible after modifying the Session. If you have a framework that does not use Session Lock, you should be aware that concurrency issues can occur.

Conclusion

So far, I tried to reproduce and solve the problem caused by Session Lock. Through this process, you can derive the following recommendations:

• You need to know what lock policy your session handler is using.
• The PHP default session handler is a file, which locks Session Data.
• The Redis Session Handler does not lock. Options allow you to change the lock policy.
• The Memcached Session Handler locks. Options allow you to change the lock policy.
• If the session handler is using Lock, you must unlock it after modifying the Session. (session_write_close).
• You should be aware that concurrency issues can occur if the session handler is not locking, and you should not store data that requires integrity in the Session.