nicktacular / php-mongo-session Goto Github PK

@nicktacular

First off, thank you for creating the MongoSession class. It really helped me out on a project. I did something a bit crazy to it, so I didn't want to issue a Pull Request but I wanted to let you know how I modified your class so that locks aren't needed at all.

As you know, PHP does a read lock by default for the entire life of the script that called session_start(). The downside to this is if you ever fire off multiple script invocations for the same user at the same time. In the old days this only happened with framesets but we run into slowdowns due to multiple async ajax calls all the time. I decided to remove this paradigm completely and I want to let you know how I did it.

I first removed any reference to the lock method. This was really only in the read method anyway. I changed the session.serialize_handler to php_serialize. I'll explain why in just a bit. Next I changed the write method to the following:

     * Save the session data.
     * @param  string $sid The session ID that PHP passes.
     * @param  string $data The session serialized data string.
     * @return boolean True always.
     */
    public function write($sid, /*string*/
                          $data) {
        //update/insert our session data
        $this->sessionDoc = $this->sessions->findOne(array('_id' => $sid));
        if (!$this->sessionDoc) {
            //print "COUDN'T FIND SID: $sid<p>";
            $this->sessionDoc = array();
            $this->sessionDoc['_id'] = $sid;
            $this->sessionDoc['started'] = new MongoDate();
        }

        //there could have been a session regen so we need to be careful with the $sid here and set it anyway
        if ($this->sid != $sid) {
            //set the new one
            $this->sid = $sid;

            //and also make sure we're going to write to the correct document
            $this->sessionDoc['_id'] = $sid;
        }

        //loop through the session array and only store things where now is more recent
        $session_data_array = unserialize($this->sessionDoc['data']->bin);
        //print "<pre>DATA: $data\n\n\nSESSION DATA ARRAY: ".print_r($session_data_array, true);
        $data_array = unserialize($data);
        //print "DATA ARRAY: ".print_r($data_array, true);
        $something_changed = false;
        foreach ($data_array as $key => $val) {
            if (strpos($key, '_SMT') !== false) {
                //ignore the meta timestamp keys
                continue;
            }
            if (!isset($session_data_array[$key])) {
                //we are storing something new so just write it with a timestamp entry
                $session_data_array[$key] = $val;
                $session_data_array[$key.'_SMT'] = $_SERVER['REQUEST_TIME_FLOAT'];
                $something_changed = true;
            } else {
                //ok there is an existing key
                if (serialize($session_data_array[$key]) != serialize($val)) {
                    //session key val has changed so update only if the script that wrote it
                    //is older than the microtime of when our script started
                    if (!isset($session_data_array[$key.'_SMT'])) {
                        //for whatever reason there is no timestamp for this entry
                        //so assume that we are the winner here
                        $session_data_array[$key] = $val;
                        $session_data_array[$key.'_SMT'] = $_SERVER['REQUEST_TIME_FLOAT'];
                        $something_changed = true;
                    } else {
                        //there is a timestamp value so check to make sure that we are newer
                        if ($session_data_array[$key.'_SMT'] < $_SERVER['REQUEST_TIME_FLOAT']) {
                            $session_data_array[$key] = $val;
                            $session_data_array[$key.'_SMT'] = $_SERVER['REQUEST_TIME_FLOAT'];
                            $something_changed = true;
                        }
                    }
                }
            }
        }

        //now we need to loop through $session_data_array to see if any keys have been deleted
        foreach ($session_data_array as $key => $val) {
            if (strpos($key, '_SMT') !== false) {
                //ignore the meta timestamp keys
                continue;
            }
            if (!isset($data_array[$key])) {
                //the key is no longer in our memory data array
                if (!isset($session_data_array[$key.'_SMT'])) {
                    //for whatever reason there is no timestamp for this entry
                    //so assume that we are the winner here
                    unset($session_data_array[$key]);
                    $something_changed = true;
                } else {
                    //there is a timestamp value so check to make sure that we are newer
                    //delete only if the script that wrote it
                    //is older than the microtime of when our script started
                    if ($session_data_array[$key.'_SMT'] < $_SERVER['REQUEST_TIME_FLOAT']) {
                        unset($session_data_array[$key]);
                        unset($session_data_array[$key.'_SMT']);
                        $something_changed = true;
                    }
                }
            }
        }

        //print "FINAL SESSION ARRAY: ".print_r($session_data_array, true);

        if ($something_changed) {
            //print "SOMETHING CHANGED!";
            $this->sessionDoc['last_accessed'] = new MongoDate();
            $this->sessionDoc['data'] = new MongoBinData(serialize($session_data_array), MongoBinData::BYTE_ARRAY);

            //print "sessionDoc: ".print_r($this->sessionDoc, true);

            $this->sessions->save($this->sessionDoc, $this->getConfig('write_options'));
        } else {
            //print "NOTHING CHANGED!";
        }
        return true;
    }

Basically on write() I hit the mongo db for the session data and unserialize it into an array called $session_data_array. I then take the $data string and unserialize it into $data_array. I then proceed to diff the in memory $data_array vs. the last entry in mongo ($session_data_array) the following way.

If there is an entry in $data_array that is not set in $session_data_array then go ahead and create the key in $session_data_array as well as a microtime timestamp from when the script was first invoked. Since 5.4 this is available in $_SERVER['REQUEST_TIME_FLOAT'] (I know you are trying to support 5.2 and I could've created a property called startMicrotime and set it to microtime(true) in __construct, but I was a bit lazy.

Ok, if there is an entry in $data_array that is set in $session_data_array first check to see if it is different than the same value that is already in $session_data_array. If it is different then it looks for the timestamp of the last script that updated that key. If the timestamp of the running script (i.e. when it started) is newer than the timestamp on the session key then it updates that key value and it's corresponding $key.'_SMT' to be the new timestamp. (_SMT was a suffix I thought wouldn't collide much with apps and stands for Session Micro Time)

Last but not least, it loops through the $data array looking for the removal of any keys (i.e. you did an unset($_SESSION['foo'])) It does the similar timestamp check and if this script is newer than it wins.

After all is said and done it only updates mongo if, in fact, something in the session data has changed. If it hasn't it doesn't waste the network round trip by saving the same data over itself.

Cons to this approach:

• For every key in the $_SESSION array there is a corresponding $key.'_SMT' along with a float for the microtime. This adds a fair amount of bloat to what's in the session. However, since sessions don't tend to massively huge it may be a fair tradeoff for the no lock functionality. Each app is different, your results may vary.
• Using unserialize() and serialize() instead of the default session_decode and session_encode adds a fair amount of bloat but for our app and purposes we were willing to do it.

You may be asking yourself why didn't he just use session_decode() and session_encode()? The problem is that session_decode only returns a boolean and actually manipulates $_SESSION. I can't have the write method potentially jacking up that super global so I wanted to be able to decode and encode it to my own variables without touching $_SESSION and having inadvertent side effects.

I also set about on this journey because after using MongoSession in production for a day I noticed stale locks in the locks table. I also had users report to me that they couldn't login and in fact I was able to figure out that they were stuck in the immutable lock problem that you referenced in your README I believe.

My fork is located at https://github.com/mikeytag/php-mongo-session if you want to browse around and see the other changes I made in the file (had to add an ini_set at the top to change the session handler. My fork is now in production and will receive about 10,000 visitors each day. I'll report back with any issues that may arise. Like I said before, I am going out on a bit of limb here and I am confident in the way my app uses sessions that everything will be fine, but I realize that pulling in my changes to your repo may not be the best course of action as it's a pretty drastic change.

TL;DR: $_SESSION key level locking, saving of writes to Mongo, bloat of $_SESSION array and more.

@nicktacular do you have any objections to modifying the basic logging output to be delmiter-based -- or structured consistently in some way so it's parse-able?

I'd like to import my session logging into my logstash server so I can monitor average lock wait times, expired lock waits, etc via my ELK stack (elasticsearch+logstash+kibana).

But I cannot control the output entirely via the current 'logger' configuration. It would be best if the ->log() function were to pass raw name/value pairs for example so I can handle them properly from mongo_logger() (my function).

I guess I could just explode(':', $msg) on the message that is coming in, but even that won't work consistently because some of the log messages are just random strings.

I am thinking basically we break $msg apart into two inputs.

So you would have something like;

$this->log('lock_wait_exceeded','.3502s');

Instead of:

$this->log('LOCK_WAIT_EXCEEDED:.3502s');

Maybe the generic messages like 'Lock acquired @ ...' would simply be given an action of 'message' or something like that.

Again something like,

$this->log('message','Lock acquired @ xxxx');

Instead of

$this->log('Lock acquired @ xxxx');

This way your logger function can actually handle the parameters separately.

Perhaps we might need to add a way for it to be backwards compatible, so maybe add them as optional params.

IE,

function log($msg, $priority=10, $opts=array()){

I figured I would open an issue for this as it's definitely something that should at least be on the radar.

The Mongo class is currently used for the connection to Mongo. This class extends MongoClient, and has been deprecated (http://php.net/manual/en/class.mongo.php).

"This class has been DEPRECATED as of version 1.3.0. Relying on this feature is highly discouraged. Please use MongoClient instead. "

The replacement of Mongo with MongoClient should be simple, the bigger part would be verifying/replacing any other functions being used from the defunct Mongo class (if any).

NOTE: I wouldn't mind tackling this if my work will get merged.

So that it would be possible to install your module via composer. Could you do that please?

The description says it all. Spinoff from #14.

@nicktacular do you have the issue of old locks getting stuck in sessions_locks? I have logging enabled when one of these occurred and I don't see any exceptions or anything.

I am debugging further into the raw http logs, but I am wondering if you guys have this occur?

Maybe adding some cleanup to gc() for old records in sessions_locks?

If #14 ends up a no-go, I was thinking it might be interesting to add a read-only mode which would allow applications to access locked sessions, but prevent writes.

For scenarios where a bunch of separate sections of a site are loading via ajax (and not writing to the session, only reading), this would enable you to have true asynchronous requests to the same session.

This implementation would of course still require a lock for write access.

Currently the read() method is requiring a lock.

https://github.com/nicktacular/php-mongo-session/blob/master/MongoSession.php#L201
You're opening a mongo connection here. I'm guessing that anyone wanting to store PHP sessions in Mongo wants to do so because their PHP code already uses Mongo, so why open a 2nd connection? It should let me pass in my existing connection.

I am trying to modify your class to save data in json format instead of binary. So I tried to modify https://github.com/nicktacular/php-mongo-session/blob/master/MongoSession.php#L385 to

return json_decode($this->sessionDoc['data']);

and https://github.com/nicktacular/php-mongo-session/blob/master/MongoSession.php#L418 to $this->sessionDoc['data'] = json_encode($_SESSION);

The problem that this clears the session data (basically does not work). Is there a way to save data in json format?

The class is using the now deprecated ensureIndex() function. I noticed this when adding the role, ensureIndex isn't included in the read/write db role.

createIndex should be used for mongo > 1.5.0, and ensureindex should be used for previous versions.

So I have a simple replicaSet -- the typical/minimal 3-node (2 nodes + arbiter). I am getting fatal errors for 15-30 seconds after updates/manual failovers, I assume during the election/reelection process.

Here is the stack trace.

[13-Feb-2015 03:29:28 UTC] PHP Fatal error:  Uncaught exception 'MongoConnectionException' with message 'No candidate servers found' in /usr/share/php-share/php/php-mongo-session/MongoSession.php:204
#0 /usr/share/php-share/php/php-mongo-session/MongoSession.php(204): MongoClient->__construct('mongodb://10.10...', Array)
#1 /usr/share/php-share/php/php-mongo-session/MongoSession.php(149): MongoSession->__construct()
#2 /usr/share/php-share/php/php-mongo-session/MongoSession.php(165): MongoSession::instance()
#3 /usr/share/php-share/php/php-mongo-session/init.php(63): MongoSession::init()
  thrown in /usr/share/php-share/php/php-mongo-session/MongoSession.php on line 204

So basically this is occurring for a 15-30 second period whenever I my stack is resetting after an upgrade/manual failover of master before an upgrade. I think this is just the delay from the mongo stack electing/reelecting the master perhaps.

In either case -- this line is the culprit:

        $this->conn->connect();

We aren't doing any exception catching on this connection attempt at all -- so during this period all of my sites end up with a blank page/fatal error.

@nicktacular do you experience downtime of any sort like this when performing minor updates? (not talking about upgrades)

I am thinking in this scenario we would push out the configured PHP timeout by X seconds, and then wait for X seconds and retry the connection attempt after X seconds (in the catch block wrapped around the connection attempt).

@nicktacular curious of your thoughts/suggested solutions -- but I'll probably do something locally and test because I have a minor update I need to do on my cluster so will be a good test. Please let me know your practice/experience with installing updates on your cluster.

Okay so lock() is updated to properly ignore the duplicate key and drops out on the wtimeout exception correctly (instead of retrying for $locktimeout).

Testing the write concern support I've added, I spotted a potential issue. In the event that a write concern error occurs, the lock remains on the nodes it did properly write to.

mongodb:
"wtimeout causes write operations to return with an error after the specified limit, even if the required write concern is not fulfilled. When these write operations return, MongoDB does not undo successful data modifications performed before the write concern exceeded the wtimeout time limit."

I confirmed that firing off an unlock() in the event of a replication timeout (wtimeout), the lock is successfully removed, although you will end up with a second wtimeout occuring on that unlock event.

I have these changes local still, but I confirmed it works. As is, this works. The only negative is that you end up waiting for wtimeout twice in that event.

So if you have wTimeoutMS set to 5000, you'll wait 10 seconds total for both the lock and subsequent unlock to timeout.

                   if(preg_match('/duplicate key error/i', $e->getMessage())){
                    //duplicate key may occur during lock race, try again
                    continue;
+                 }elseif(preg_match('/replication timed out/i', $e->getMessage())){
+                   //replication error, force unlock to prevent lock-out
+                   $this->lockAcquired = true;
+                   $this->unlock($sid);
                  }else{
                    //log exception and fail lock
                    $this->log('exception: ' . $e->getMessage());

I believe the lock function has a racing condition. Two different threads might check the lock of the same session id at the same time and find that it is not locked. Then, they will race to lock the session. The one that locks first will work. The other one will get a duplicate id exception and fail. I believe it should wait for the lock to be released instead of completely failing.

When defining $config['repicaSet'] and using multiple hosts in the URI, I am getting the following exception from the secondary:

[Sun Jul 27 18:06:35 2014] [warn] [client 71.179.201.210] mod_fcgid: stderr: PHP Fatal error:  Uncaught exception 'MongoCursorException' with message '10.103.30.33:27017: not master and slaveOk=false' in /home/kyler/repos/php-mongo-session/MongoSession.php:283

.slaveOk() needs to be called to allow a read query from a secondary or this exception is thrown. I get the same error from the mongo CLI on my secondary.

slaveOk() is now deprecated and 'Read Preferences' are now supposed to be used. So it would need to fallback to slaveOk() if Read Prefs are not available. http://php.net/manual/en/mongo.readpreferences.php

In some places the write configs are explicit and in others they use a getter. Need to be consistent for this otherwise it's unclear when we want safe (w>0) or unsafe (w==0) writes.

@nicktacular I was curious if you've done any testing on mongodb 3.0 using the new wiredtiger storage engine?

I plan to do the drop-in upgrade from 2.6 to 3.0 on my testbed and I will confirm that drop-in replacement works fine (I don't expect any issues).

BUT, I am definitely going to do more testing once switching out the storage engine.

3.0 boasts up to 10x performance -- while using 80% less disk space.

http://docs.mongodb.org/manual/release-notes/3.0-upgrade/

I have been trying to debug the fact I am ending up with records in sessions_locks (sessions getting stuck locked).

After further debugging, I confirmed an exception is occurring on the UNLOCK.

"unlock exception: no lock acquired for uoobqnavd5a43gjt7e1qk7j0d5"

This may be a bug introduced from my changes.

The default config setting for cache is currently set to "private_no_expire" and the setting for cache_expiry is set to 10.

The defaults in PHP are actually "nocache" and 180. This caused an issue for our app that I caught today but I think it makes sense that php-mongo-session's defaults should be the same as PHP out of the box for things like this. I have changed my default config to:

        'cache' => 'nocache',
        'cache_expiry' => 180,//minutes

I recommend that the settings be updated in master to have these important settings (they control the headers passed to clients) set to PHP defaults.

After adding write concern support, I found a problem with the current way the exceptions are being handled in lock().

RE: "may occur if there's a race to acquire a lock"

When using a write concern value that's too high, the wTimeoutMS value is essentially ignored with this behavior.

ex) I have two nodes, so w=2 works perfect. I decreased the wTimeoutMS to 5s, so when setting w=3 I should expect to get an exception... BUT, you are catching that exception and continuing to the next iteration. Because of this, instead of wTimeoutMS stopping script execution, it keeps running until either $config['locktimeout'] is exhausted, because it thinks it's simply retrying the lock.

I will investigate the exception scenarios and see if I can add some logic to differentiate between these two scenarios, so the script properly throws an exception when wTimeoutMS is exhausted.

I'm creating this issue as a spin-off from #9 which was concerning abandoned session locks ending up in sessions_lock.

It was confirmed this is occurring when a PHP ends fatally due to a timeout for example.

As @nicktacular mentioned, we should investigate to see whether a registered PHP shudown function would even trigger in this scenario, and if it does actually trigger we should try to catch this and remove the lock.

Otherwise, we're going to need some sort of garbage collection process/monitor. I would prefer a solution that doesn't require a separate process.