Errors from FuelPHP's database code after several successful requests

[tabacco]

I'm seeing a weird set of errors from my site running in a vagrant vm under hhvm. I haven't done any tweaking of the hhvm configs, it's just a stock install of hhvm-fastcgi in place of php-fpm.

This is FuelPHP 1.7.1 (the latest version) and hhvm 2.4.1 (from the official packages for Ubuntu 12.04).

The weird part is that the site works perfectly for about the first 10-20 requests (the actual number varies), then I start getting 500s and these errors start appearing in the logs:

HipHop Fatal error: Uncaught exception 'Fuel\\Core\\PhpErrorException' with message 'array_map() expects parameter 1 to be a valid callback' in /vagrant/idlethumbs/fuel/core/classes/database/query/builder/select.php:422\nStack trace:\n#0 /vagrant/idlethumbs/fuel/core/bootstrap.php(98): Fuel\\Core\\Error::error_handler()\n#1 (): {closure}()\n#2 /vagrant/idlethumbs/fuel/core/classes/database/query/builder/select.php(422): array_map()\n#3 /vagrant/idlethumbs/fuel/core/classes/database/query.php(259): Fuel\\Core\\Database_Query_Builder_Select->compile()\n#4 /vagrant/idlethumbs/fuel/packages/orm/classes/query.php(1198): Fuel\\Core\\Database_Query->execute()\n#5 /vagrant/idlethumbs/fuel/app/classes/controller/about.php(20): Orm\\Query->get()\n#6 (): Controller_About->action_index()\n#7 /vagrant/idlethumbs/fuel/core/classes/request.php(444): ReflectionMethod->invokeArgs()\n#8 /vagrant/idlethumbs/public/index.php(49): Fuel\\Core\\Request->execute()\n#9 {main}

HipHop Fatal error: Uncaught exception 'Fuel\\Core\\PhpErrorException' with message 'array_map() expects parameter 1 to be a valid callback' in /vagrant/idlethumbs/fuel/core/classes/database/query/builder/select.php:422
Stack trace:
#0 /vagrant/idlethumbs/fuel/core/bootstrap.php(98): Fuel\\Core\\Error::error_handler()
#1 (): {closure}()
#2 /vagrant/idlethumbs/fuel/core/classes/database/query/builder/select.php(422): array_map()
#3 /vagrant/idlethumbs/fuel/core/classes/database/query.php(259): Fuel\\Core\\Database_Query_Builder_Select->compile()
#4 /vagrant/idlethumbs/fuel/packages/orm/classes/query.php(1198): Fuel\\Core\\Database_Query->execute()
#5 /vagrant/idlethumbs/fuel/packages/orm/classes/query.php(1270): Orm\\Query->get()
#6 /vagrant/idlethumbs/fuel/app/classes/model/slug.php(9): Orm\\Query->get_one()
#7 /vagrant/idlethumbs/fuel/app/classes/controller/show.php(359): Model_Slug::find_slug()
#8 /vagrant/idlethumbs/fuel/app/classes/controller/show.php(84): Controller_Show::get_podcast_by_slug()
#9 (): Controller_Show->action_show()
#10 /vagrant/idlethumbs/fuel/core/classes/request.php(444): ReflectionMethod->invokeArgs()
#11 /vagrant/idlethumbs/public/index.php(49): Fuel\\Core\\Request->execute()
#12 {main}

By way of rough debugging, I added a var_dump and exit there and confirmed that the argument was in fact an array. That also exposed some earlier E_WARNINGs from the framework:

Warning!
ErrorException [ Warning ]: Invalid operand type was used: Invalid type used as key
COREPATH/classes/database/connection.php @ line 64:
63: 
64: if ( ! isset(static::$instances[$name]))
65: {

Warning!
ErrorException [ Warning ]: Illegal offset type
COREPATH/classes/database/connection.php @ line 129:
128:    // Store the database instance
129:    static::$instances[$name] = $this;
130:    }

Warning!
ErrorException [ Warning ]: Invalid operand type was used: Invalid type used as key
COREPATH/classes/database/connection.php @ line 84:
83: 
84: return static::$instances[$name];
85: }

Notice!
ErrorException [ Notice ]: Undefined index: default
COREPATH/classes/database/connection.php @ line 84:
83: 
84: return static::$instances[$name];
85: }

In all of these cases I confirmed that $name was the string "default".

I can 'fix' the error by restarting hhvm-fastcgi, then reproduce it again by just refreshing any page that does database access until it starts failing. Pages that don't do database access continue to work fine.

Please let me know if there's any other info I can get you that might be helpful!

[tabacco]

Just an update to confirm I can still reproduce this in hhvm 2.4.2

[scannell]

Thanks for reporting this. Feel free to submit a PR if you (or someone else reading this) gets to this before we do.

[scannell]

An isolated repro for this would be great and help get this addressed. (We're not familiar with FuelPHP and it's not something we're testing at the moment, CC: @JoelMarcey)

[tabacco]

I doubt it's within my skillset to fix and submit a PR, but I'll at least try to get you a repro case in the next couple of days.

[fredemmott]

Do you still have this issue with HHVM 3? If so, could you also try the nightlies.

[tabacco]

Confirmed it's still happening in 3.1 - looks like you don't build nightlies for Saucy, so I'll have to get a Trusty VM going later this weekend to try it out. I also still owe you guys a test case, which I'll try to do this weekend as well.

[fredemmott]

Thanks - 3.1 wasn't out when I last commented; it's fairly unlikely we've fixed it in master since then, so don't worry too much about the nightlies.

An isolated test case would still greatly help :)

[tabacco]

Sample app that exhibits the issue: https://www.dropbox.com/s/l4teuxo4ofxiu7p/hhvm_2011_repro.tar.gz

Steps to set up:

1. Untar
2. Set doc root to hhvm_2011_repro/public
3. Set mysql connection details in hhvm_2011_repro/fuel/app/config/db.php to suit your tastes
4. In the root of the project, run php oil refine migrate:current
5. Navigate to http://[host]/index.php
6. Refresh 10-20 times

Alternatively, if you prefer to skip the migration portion, you can just do:

CREATE TABLE `demos` (
  `id` int(5) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8

Let me know if that works for you. Sorry it's complicated with the database setup, but since the issue is in the framework's db code I couldn't think of a better way. The fuel orm doesn't support sqlite yet, unfortunately.

[Crux-One]

@tabacco I was also confronted with the same problem on FuelPHP1.7.1 and I've fixed the connection.php source as below.

$instance = static::$instances[$name];

return $instance;

HHVM seems working well so far.

[ptarjan]

@Crux-One what did the code look like before when it didn't work? Can you make a small test case?

[tabacco]

@ptarjan I'm guessing he's referring to https://github.com/fuel/core/blob/1.7/master/classes/database/connection.php#L85 as it's the one quoted in the error in my earlier comment.

The original line is:

return static::$instances[$name];

I can try and confirm the fix tomorrow in the test case I posted earlier. I can also try to make a smaller test case this weekend.

[yswery]

I am getting this error too. But the fix posted by @Crux-One and @tabacco doesnt seem to be working for me, the ERROR is still on line 65 not 85 for me

Invalid operand type was used: Invalid type used as key in fuel/core/classes/database/connection.php on line 65

[Crux-One]

@yswery It was working fine for me before reboot HHVM I guess, then just suddenly I have reproduced a bug. That is incorrect solution that I have posted.

[JoelMarcey]

@tabacco @Crux-One Is there any way to ferret out a small, reproducible test case from Fuel (that optimally doesn't depend on Fuel) that can be used to track this problem down?

[yswery]

After spending lots of time with this I found that FuelPHP runs though this function twice on initialisation.

first time round the input param $name is null and will get set as a string mostly "default" but on the second iteration it will be passing a full object as $name as seen below:

string(7) "default"

object(Fuel\Core\Database_PDO_Connection)#118 (8) {
  ["_connection":protected]=>
  NULL
  ["_identifier":protected]=>
  string(1) "`"
  ["_db_type"]=>
  string(0) ""
  ["last_query"]=>
  NULL
  ["_instance":protected]=>
  string(7) "default"
  ["_in_transaction":protected]=>
  bool(false)
  ["_transaction_depth":protected]=>
  int(0)
  ["_config":protected]=>
  array(9) {
    ["type"]=>
    string(3) "pdo"
    ["connection"]=>
    array(5) {
      ["persistent"]=>
      bool(false)
      ["compress"]=>
      bool(false)
      ["dsn"]=>
      string(31) "mysql:host=localhost;dbname=website"
      ["username"]=>
      string(4) "root"
      ["password"]=>
      string(8) "password"
    }
    ["identifier"]=>
    string(1) "`"
    ["table_prefix"]=>
    string(0) ""
    ["charset"]=>
    string(4) "utf8"
    ["collation"]=>
    bool(false)
    ["enable_cache"]=>
    bool(true)
    ["profiling"]=>
    bool(false)
    ["readonly"]=>
    bool(false)
  }
}

to get this I put a var_dump() just before line 65 (where things go wrong.

so I assume things go wrong when we pass a full object to the static array in this scenario.

I quick hack and fix for this case is to add a line just before line 64 on fuel/core/classes/database/connection.php

settype($name, 'string');

converting the object into a string. this seemed have fixed it for me.

[JoelMarcey]

@tabacco Hi! Reading through this, I am not sure if this is an HHVM issue still or if it was a FuelPHP bug that was fixed by @yswery. Can you confirm? Thanks.

[paulbiss]

Closing due to inactivity.

https://github.com/facebook/hhvm/wiki/Human-Timeouts