Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Opcache is a problem with the FileSystem driver #135

Merged
merged 4 commits into from
Mar 30, 2014
Merged

Opcache is a problem with the FileSystem driver #135

merged 4 commits into from
Mar 30, 2014

Conversation

CMCDragonkai
Copy link
Contributor

This is a bit of a long story.

I've been working with tedivm/Stash for a while for an Authentication and Authorisation library. I was using the FileSystem driver for file based sessions. It was working for a long time, both from a Windows computer and on hosted Ubuntu system on Digital Ocean.

However I recently started testing it on my Ubuntu VM which runs on the same kind of specs as the Digital Ocean's VM in order to simulate a closer environment to production.

And then the session management broke.

I started logging everything to figure out what was happening. And what was happening was this, but let me describe the context first.

<?php 
/* Cachekey: cache/polyauthqkc1z5m33e/ */
/* Type: array */
$expiration = 1394941347;
$data = array();

/* Child Type: array */
$data['return'] = unserialize(base64_decode('YToxOntzOjc6InVzZXJfaWQiO2I6MDt9'));

/* Child Type: integer */
$data['createdOn'] = 1394901250;

Here is the included file (cached file). The returned variable should end up being: ["user_id" => false];

I know this is the real file content prior the the include command because I wrote this as a part of my logger:

//...line 141
\FB::log(file_get_contents($path), 'FILE CONTENT PRIOR TO INCLUSION');

include($path);
//...etc

And it showed the above file content exactly prior to inclusion.

Now the next thing I did was log the $data variable.

//...line 141
\FB::log(file_get_contents($path), 'FILE CONTENT PRIOR TO INCLUSION');

include($path);

\FB::log($data, 'DATA VARIABLE');
//...etc

This is where the discrepancy appeared.

On my Windows (Apache + mod_php) system it showed:

       "data"       => [
           "return"    => [
               "user_id" => false
           ],
           "createdOn" => 1394901250
       ]

On my Ubuntu Digital Ocean VM it would show the same since the session management was working.

However on my Ubuntu VirualBox VM it would show:

       "data"       => [
           "return"    => [],
           "createdOn" => 1394901250
       ]

Exactly the same createdOn timestamp, but an empty return array!?

Needless to say, this made session management impossible, since none of the sessions could ever be remembered.

Now the error goes away, and still works with all environments, if you instead use eval with file_get_contents:

eval('?>' . file_get_contents($path));

This technique is exactly equivalent to using include (the ?> basically allows the file to start with <?php). See this: http://stackoverflow.com/questions/1184628/php-equivalent-of-include-using-eval

I don't know why this error occurs. I don't have enough knowledge about the PHP internals why include doesn't work but this does. It might have something to do with opcode or caching.

I also did some benchmarking. Zero microtime difference.

This is a bit of a long story.

I've been working with tedivm/Stash for a while for an Authentication and Authorisation library. I was using the FileSystem driver for file based sessions. It was working for a long time, both from a Windows computer and on hosted Ubuntu system on Digital Ocean.

However I recently started testing it on my Ubuntu VM which runs on the same kind of specs as the Digital Ocean's VM in order to simulate a closer environment to production.

And then the session management broke.

I started logging everything to figure out what was happening. And what was happening was this, but let me describe the context first.

```
<?php 
/* Cachekey: cache/polyauthqkc1z5m33e/ */
/* Type: array */
$expiration = 1394941347;
$data = array();

/* Child Type: array */
$data['return'] = unserialize(base64_decode('YToxOntzOjc6InVzZXJfaWQiO2I6MDt9'));

/* Child Type: integer */
$data['createdOn'] = 1394901250;
```

Here is the included file (cached file). The returned variable should end up being: `["user_id" => false]`;

I know this is the real file content prior the the include command because I wrote this as a part of my logger:

```
//...line 141
\FB::log(file_get_contents($path), 'FILE CONTENT PRIOR TO INCLUSION');

include($path);
//...etc
```

And it showed the above file content exactly prior to inclusion.

Now the next thing I did was log the `$data` variable.

```
//...line 141
\FB::log(file_get_contents($path), 'FILE CONTENT PRIOR TO INCLUSION');

include($path);

\FB::log($data, 'DATA VARIABLE');
//...etc
```

This is where the discrepancy appeared.

On my Windows (Apache + mod_php) system it showed:

```
       "data"       => [
           "return"    => [
               "user_id" => false
           ],
           "createdOn" => 1394901250
       ]
```

On my Ubuntu Digital Ocean VM it would show the same since the session management was working.

However on my Ubuntu VirualBox VM it would show:

```
       "data"       => [
           "return"    => [],
           "createdOn" => 1394901250
       ]
```

Exactly the same createdOn timestamp, but an empty return array!?

Needless to say, this made session management impossible, since none of the sessions could ever be remembered.

Now the error goes away, and still works with all environments, if you instead use eval with file_get_contents:

```
eval('?>' . file_get_contents($path));
```

This technique is exactly equivalent to using include (the `?>` basically allows the file to start with `<?php`). See this: http://stackoverflow.com/questions/1184628/php-equivalent-of-include-using-eval

I don't know why this error occurs. I don't have enough knowledge about the PHP internals why include doesn't work but this does. It might have something to do with opcode or caching.

I also did some benchmarking. Zero microtime difference.
@tedivm
Copy link
Member

tedivm commented Mar 16, 2014

This technique is, unfortunately, not the same as simply using include.

One difference is when you're using an opcode cache. They will take the php in the file, compile it, run, and then in the future allow PHP to skip that compiling process. This can shave as much as 25% off of the operation.

Another, and probably bigger, reason is that a lot of people disable the eval function if their projects aren't using it, as it can be used maliciously in a few ways. The less extreme option is to just log the evals, but if Stash were using it this way it would fill the logs rather quickly with a bunch of garbage.

Due to that change I would consider this a backwards compatibility breaking addition, and would need some solid reasons to support it. Ultimately I'd prefer to find out the real underlying problem that's occurring here. Would you mind making a gist with your php.ini file and the output of phpinfo, so I can take a look at what's happening here?

@CMCDragonkai
Copy link
Contributor Author

Here's my phpinfo(): https://gist.github.com/anonymous/9594936
(I tried outputting via CLI but then I realised the php-cli has a completely different ini file, might want to load it as a html file)

Here's my php.ini: https://gist.github.com/anonymous/9594915

@tedivm
Copy link
Member

tedivm commented Mar 17, 2014

Have you tried disabling the opcode cache? In your current file it's not disabled, and phpinfo output file shows that it's one. If you want to leave it on, set opcache.revalidate_freq to 0 or opcache.blacklist_filename to exclude your cache directory.

@CMCDragonkai
Copy link
Contributor Author

That would be in the php.ini? Why would phpinfo() show it being used, while the ini doesn't actually activate it?

Also this new fangled opcache thing is causing quite a few problems, with capistrano/rocketeer and now this.

@tedivm
Copy link
Member

tedivm commented Mar 17, 2014

Maybe PHP isn't using the php.ini file you think it is? Are you sure you're looking at /etc/php5/fpm/php.ini ?

@CMCDragonkai
Copy link
Contributor Author

I'll be able to check in a week when I get back to my desktop computer where this occurred.

@CMCDragonkai
Copy link
Contributor Author

Hey @tedivm You are right. It is indeed Opcache causing this problem. However it cannot be solved from the PHP.ini, and I don't think we should expect people's PHP.ini to be properly configured.

There is a current bug report here: https://bugs.php.net/bug.php?id=65559

Basically since the switching of APC to Opcache, there's actually a BC problem. And it's described in the above bug report.

I tried changing the options in the ini file. But they didn't work. What worked is this function:

if(function_exists('opcache_invalidate')){
    opcache_invalidate($path, true);
}
include($path);

See the function here http://www.php.net/manual/en/function.opcache-invalidate.php

The second parameter of true is required, because when the changes to the file is very fast (below 1 second), there's no timestamp difference, requiring us to invalidate the cache.

This was not required in APC, as there was a hack to make this work before.

I think we need to use something other than "include" for filesystem cache, it seems PHP developers did not consider that include might be used for non-source code files that change during runtime.

@CMCDragonkai CMCDragonkai changed the title Switched include() to using eval + file_get_contents instead Opcache is a problem with the FileSystem driver Mar 26, 2014
@CMCDragonkai
Copy link
Contributor Author

I've modified the commit to use opcache_invalidate if it exists.

I think this is probably the best solution, since people still using APC will get the benefits of caching. People using Opcache won't need to worry and Stash will "Just Work". Besides if they wanted to control it from the php.ini, they would need to change invalidation for everything (which is inefficient), or blacklist the cache directory (which is a PITA).

@tedivm
Copy link
Member

tedivm commented Mar 26, 2014

Rather than put the "opcache_invalidate" function in "get" function, put it in the "storeData" function right after writing the file. This way people using Opcache and APC will still get the benefits- it's also just more efficient in general.

Once that's changed I'll be happy to merge this back in- excellent find on this!

@tedivm
Copy link
Member

tedivm commented Mar 26, 2014

Oh, and if you don't mind, can you throw in a small comment above the opcache_invalidate if block you're making and mention why it's occurring? That way people will know what's up if they play with this code in the future.

@CMCDragonkai
Copy link
Contributor Author

Where would you suggest to put it in storeData? Also would this be before or after we write to the file? One thing though, this means the cache is invalidated for the system that wrote the file, but not for any system that is reading the file but did not write the file. Imagine 2 caching systems using the same source.

@tedivm
Copy link
Member

tedivm commented Mar 27, 2014

Immediately after you write the file you should call the opcache_invalidate function.

I'm not sure what you mean about it only invalidating it for "the system that wrote the file". If you have scripts Alpha.php and Beta.php, and Alpha.php writes a new cache script that calls opcache_invalidate, then Beta.php will load the right file, not a stale one.

@CMCDragonkai
Copy link
Contributor Author

Oh I mean like different systems using different opcode cache or even different languages/apps.

@CMCDragonkai
Copy link
Contributor Author

Oh wait thats a non issue dw. Ill do some tests and get back to this.

@CMCDragonkai
Copy link
Contributor Author

In order to put it after storeData, the file_put_contents needs to be separated from the return statement. I'm going to make that change and add in the comment. However if in the future we get different serialisation strategies, we'll need change how do this, as non PHP files will not get cached by opcache.

@CMCDragonkai
Copy link
Contributor Author

It's done. Please check @tedivm

@CMCDragonkai
Copy link
Contributor Author

Hey @tedivm any news on this?


// If opcache is switched on, it will try to cache the PHP data file, essentially "caching the cache"
// This can cause problems since when we try to retrieve the cache data, it might not equal the data source.
// Therefore we have to invalidate the opcode cache for all PHP "data" files
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This comment is not accurate. The problem isn't that the files are being cached, and this does not prevent them from being cached. The issue is that the new php opcode caching system only revalidates against the source files once every few seconds, so some changes will not be caught. This fix immediately invalidates that opcode cache after a file is written, so that future includes are not using the stale opcode cached file.

@CMCDragonkai
Copy link
Contributor Author

Changed the comment.

tedivm added a commit that referenced this pull request Mar 30, 2014
Opcache is a problem with the FileSystem driver
@tedivm tedivm merged commit 4a99597 into tedious:master Mar 30, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants