Bug loading plugins at login time

[juergmessmer]

Whenever I try to log in at a site with a plugin (schulcms-plugin), calling the url domain/admin/pages) a exception is thrown and the session is killed. It doesn't happen when any other admin url is called. So far this only happens when the particular plugin schulcms is installed. It looks like it has something to do with recent changes (PluginPart, order of plugins, etc.?)

••••••••••• exception thown

[Wed May 07 11:20:16 2014] [error] [client 127.0.0.1] ([code] => 0, [message] => 'Error at offset 700 of 746 bytes', [filename] => '/Users/jmg/Sites/cms_sereal/base/lib/classes/Cache.php', [line] => 163, 
[trace] => (
  [0] => 'SplObjectStorage->unserialize()', 
  [1] => 'unserialize() in /Users/jmg/Sites/cms_sereal/base/lib/classes/Cache.php (163)', 
  [2] => 'Cache->getContentsAsVariable() in /Users/jmg/Sites/cms_sereal/base/lib/classes/SystemPart.php (111)', 
  [3] => 'SystemPart::allParts() in /Users/jmg/Sites/cms_sereal/base/lib/classes/SystemPart.php (164)', 
  [4] => 'PluginPart::allPlugins() in /Users/jmg/Sites/cms_sereal/base/lib/classes/ResourceFinder.php (490)', 
  [5] => 'ResourceFinder::getPluginPaths() in /Users/jmg/Sites/cms_sereal/base/lib/classes/ResourceFinder.php (366)', [6] => 'ResourceFinder->buildSearchPathList() in /Users/jmg/Sites/cms_sereal/base/lib/classes/ResourceFinder.php (236)', [7] => 'ResourceFinder->doFind() in /Users/jmg/Sites/cms_sereal/base/lib/classes/ResourceFinder.php (221)', [8] => 'ResourceFinder->find() in /Users/jmg/Sites/cms_sereal/base/lib/classes/Autoloader.php (51)', [9] => 'Autoloader::findIncludePath() in /Users/jmg/Sites/cms_sereal/base/lib/classes/Autoloader.php (29)', [10] => 'Autoloader::autoload()', [11] => 'spl_autoload_call()', [12] => 'session_start() in /Users/jmg/Sites/cms_sereal/base/lib/classes/Session.php (268)', [13] => 'require_once() in /Users/jmg/Sites/cms_sereal/base/lib/classes/Autoloader.php (25)', [14] => 'Autoloader::autoload()', [15] => 'spl_autoload_call() in /Users/jmg/Sites/cms_sereal/base/modules/file/widget_json/WidgetJsonFileModule.php (28)', [16] => 'WidgetJsonFileModule->renderFile() in /Users/jmg/Sites/cms_sereal/base/lib/classes/FileManager.php (21)', [17] => 'FileManager->__construct() in /Users/jmg/Sites/cms_sereal/base/lib/classes/Manager.php (91)', [18] => 'Manager::getManager() in /Users/jmg/Sites/cms_sereal/base/lib/main.php (11)', [19] => 'require_once() in /Users/jmg/Sites/cms_sereal/index.php (5)'), [referrer] => 'http://cms_sereal/admin/pages', [host] => 'cms_sereal', [path] => '/get_file/widget_json/-/destroy', [request] => ([path] => 'widget_json/-/destroy', [Session] => 'ec12b855d2b0acd2e3e3f9766d865d23'), [cookies] => ([Session] => 'ec12b855d2b0acd2e3e3f9766d865d23')), referer: http://cms_sereal/admin/pages

[sabberworm]

What is the actual error message that comes before the stack trace? Apparently unserialize isn’t successful. But why?

[juergmessmer]

Sorry, here's the message. The only thing I know is it happens while reading a cache file.

[Wed May 07 12:34:28 2014] [error] [client 127.0.0.1] ([code] => 0, [message] => 'Error at offset 704 of 1272 bytes', ...

Maybe it's the tree widget. The last cache file contains this a:5:{s:4:"path";a:3:{i:0;s:7:"modules";i:1;s:6:"widget";i:2;s:4:"tree";}s:4:"type";s:6:"widget";s:4:"name";s:4:"tree";s:7:"folders";a:1:{i:0;s:9:"templates";}s:11:"module_info";a:1:{s:7:"enabled";b:1;}}

[juergmessmer]

Now it doesn't happen anymore in one site. At the other site I click on a few pages in admin pages, logged out and logged in again. Now it doesn't happen anymore either. Have recent base changes somehow affected the serialize and unserialize?

[juergmessmer]

This seems related: I just ran rap parse-resources.php and got this message (tested in two sites)

PHP Notice: unserialize(): Error at offset 204 of 1523 bytes in /Users/jmg/Sites/cms_altenburg/base/lib/classes/Cache.php on line 163 PHP Stack trace: PHP 1. {main}() /Users/jmg/Sites/cms_altenburg/base/scripts/parse-resources.php:0 PHP 2. require() /Users/jmg/Sites/cms_altenburg/base/scripts/parse-resources.php:5 PHP 3. ResourceFinder->find() /Users/jmg/Sites/cms_altenburg/base/lib/inc.php:40 PHP 4. ResourceFinder->doFind() /Users/jmg/Sites/cms_altenburg/base/lib/classes/ResourceFinder.php:225 PHP 5. ResourceFinder->buildSearchPathList() /Users/jmg/Sites/cms_altenburg/base/lib/classes/ResourceFinder.php:236 PHP 6. ResourceFinder::getPluginPaths() /Users/jmg/Sites/cms_altenburg/base/lib/classes/ResourceFinder.php:366 PHP 7. PluginPart::allPlugins() /Users/jmg/Sites/cms_altenburg/base/lib/classes/ResourceFinder.php:490 PHP 8. SystemPart::allParts() /Users/jmg/Sites/cms_altenburg/base/lib/classes/SystemPart.php:164 PHP 9. Cache->getContentsAsVariable() /Users/jmg/Sites/cms_altenburg/base/lib/classes/SystemPart.php:111 PHP 10. unserialize() /Users/jmg/Sites/cms_altenburg/base/lib/classes/Cache.php:163

[sabberworm]

You should try to examine the following cache file: 4d72f8aa9456c58b44fbab31fc96de3a inside the config dir. This is where system parts are cached.

[juergmessmer]

I don't find such a cache file. But I opened one called 4e1d384e7e59fb63298e843c2cbb0d8d.cache and found funny <NUL> elements

[sabberworm]

serialize always uses nulls to terminate identifiers. Maybe I miscalculated the md5. Now it gives me 8e0a656bb90a4077c1a5ac541014649c.

[sabberworm]

Or just open all of them and search for the name of the class that gives the exception (SplObjectStorage).

[juergmessmer]

Here again, I just opened a few cache files, found "SplObjectStorage", closed them, cleared the cache and now executing rap parse-resources.php does not fail anymore. No idea :=)

[sabberworm]

This may be a bug in older PHP versions or an incompatibility between serialized objects of differing versions. We should have an installation with only PHP 5.3 (server and CLI) and test.

[juergmessmer]

@sabberworm is this issue still open? I think it's fixed, but I can't remember how...:=)

[juergmessmer]

766275ca8970ca5217e2b236196131375acff273 fixed this