foreach over ObjectId and Garbage Collection

[uh-zuh]

Bug Report

foreach over ObjectId changes behavior after circular reference collector.

Before GC foreach over ObjectId executes one loop iteration with $key="oid".
After GC foreach over ObjectId executes zero loop iterations.

Environment

PHP inside Docker on Windows 10.
Docker Image: php:8.2.27-apache
PHP: 8.2.27
MongoDB PHP Driver: 1.20.1
MongoDB PHP Library: 1.20.0
MongoDB: 8.0.0
mongodb/laravel-mongodb: 4.8.1

MongoDB: I run DB in separate Docker container locally and use in PHP only HOST and PORT of DB.

www-data@5c2174446320:~/html$ php -i | grep -E 'mongodb|libmongoc|libbson'
Cannot load Xdebug - it was already loaded
/usr/local/etc/php/conf.d/mongodb.ini,
mongodb
libbson bundled version => 1.28.1
libmongoc bundled version => 1.28.1
libmongoc SSL => enabled
libmongoc SSL library => OpenSSL
libmongoc crypto => enabled
libmongoc crypto library => libcrypto
libmongoc crypto system profile => disabled
libmongoc SASL => enabled
libmongoc SRV => enabled
libmongoc compression => enabled
libmongoc compression snappy => enabled
libmongoc compression zlib => enabled
libmongoc compression zstd => enabled
libmongocrypt bundled version => 1.11.0
libmongocrypt crypto => enabled
libmongocrypt crypto library => libcrypto
mongodb.debug => no value => no value

Test Script

I've used mongodb/laravel-mongodb to reproduce the bug but there is not so much Laravel specific and main issue in \MongoDB\BSON\ObjectId.

ObjectIdTestModel.php

<?php

namespace App\Models;

class ObjectIdTestModel extends \MongoDB\Laravel\Eloquent\Model
{
}

Test.php

\dump();

// Uncommenting following line fixes the test
//gc_disable();

$objectId1 = new ObjectId();
$objectId2 = new ObjectId();

// Here we see public property "oid"
echo 'objectId1: ';
xdebug_debug_zval('objectId1');
echo 'objectId2: ';
xdebug_debug_zval('objectId2');

// Check possible assumption about iterating
$is_traversable = ($objectId1 instanceof \Traversable);
echo 'is_traversable: ' . var_export($is_traversable, true) . "\n";

// Check there are no properties for iterating in foreach hence there is not property "oid"
$reflect    = new \ReflectionClass($objectId1);
$properties = $reflect->getProperties();
echo 'properties: ' . print_r($properties, true);

// Allocate a lot of objects
for ($i = 0; $i < 200; $i++) {
    $model = new ObjectIdTestModel();
    $model->save();
}
$a = ObjectIdTestModel::all();

// First foreach over \MongoDB\BSON\ObjectId
$number1 = 0;
foreach ($objectId1 as $key => $value) {
    $number1 += 1;
}

// Allocate a lot of objects again
$a = ObjectIdTestModel::all();

// Second foreach over \MongoDB\BSON\ObjectId
$number2 = 0;
foreach ($objectId2 as $key => $value) {
    $number2 += 1;
}

echo 'objectId1: ';
xdebug_debug_zval('objectId1');
echo 'objectId2: ';
xdebug_debug_zval('objectId2');

$this->assertEquals(1, $number1, 'number1');
$this->assertEquals(1, $number2, 'number2');

Test output:

objectId1: objectId1: (refcount=1, is_ref=0)=class MongoDB\BSON\ObjectId { public $oid = (refcount=1, is_ref=0)='679a97b2d1cc47db6503f004' }
objectId2: objectId2: (refcount=1, is_ref=0)=class MongoDB\BSON\ObjectId { public $oid = (refcount=1, is_ref=0)='679a97b2d1cc47db6503f005' }
is_traversable: false
properties: Array
(
)
objectId1: objectId1: (refcount=1, is_ref=0)=class MongoDB\BSON\ObjectId { public $oid = (refcount=1, is_ref=0)='679a97b2d1cc47db6503f004' }
objectId2: objectId2: (refcount=1, is_ref=0)=class MongoDB\BSON\ObjectId { public $oid = (refcount=1, is_ref=0)='679a97b2d1cc47db6503f005' }

...

  number2
  Failed asserting that 0 matches expected 1.

If the bug is not repoduced you can increase number of created objects in line for ($i = 0; $i < 200; $i++) {

Expected and Actual Behavior

Expected

$number1 === 1
$number2 === 1
Circular reference collector do not change script behavior.

Actual

$number1 === 1
$number2 === 0
Calling gc_disable() "fixes" the bug.

Preffered solution

Prohibit to iterate over \MongoDB\BSON\ObjectId especially by hidden public property "oid".
I have iterated it by mistake and prefer empty loop over object without public properties instead of strange behavior.

Debug Log

object_id_gc.zip

[jmikola]

Best I can tell, xdebug_debug_zval() in your example ends up calling the get_debug_info object handler for MongoDB\BSON\ObjectId:

• https://github.com/xdebug/xdebug/blob/45b21c242b1094e2015d044d8265f7b9b0c76919/src/lib/var_export_line.c#L273
• https://github.com/xdebug/xdebug/blob/45b21c242b1094e2015d044d8265f7b9b0c76919/src/lib/var.c#L108
• https://github.com/php/php-src/blob/php-8.4.3/Zend/zend_object_handlers.c#L2387

This ultimately calls php_phongo_objectid_get_properties_hash(), which returns a HashTable with an "oid" property; however, this is not an actual property on the ObjectId class. The string value you see is populated from another field on the internal php_phongo_objectid_t struct.

When using foreach on an ObjectId instance, the get_properties object handler should be invoked. This also returns a HashTable with an "oid" property; however, that HashTable is permanently stored on the php_phongo_objectid_t struct and later freed by the free_object handler. This is due to a conditional in PHONGO_GET_PROPERTY_HASH_INIT_PROPS on is_temp, which is only true for get_debug_info.

I looked at object_id_gc.log but it's not clear to me what in that file is relevant. I see many insert and find commands, but those should not have any impact on two ObjectId zvals created elsewhere in the script.

I was able to reduce the reproduction of an empty foreach to the following:

$oid = new MongoDB\BSON\ObjectId;

var_dump($oid);

echo "Iterating ObjectId:\n";
foreach ($oid as $k => $v) {
	printf("%s: %s\n", $k, $v);
}

printf("gc_collect_cycles: %d\n", gc_collect_cycles());

var_dump($oid);

echo "Iterating ObjectId:\n";
foreach ($oid as $k => $v) {
	printf("%s: %s\n", $k, $v);
}

Output resembles the following:

object(MongoDB\BSON\ObjectId)#1 (1) {
  ["oid"]=>
  string(24) "679d37953919f841b50f9710"
}
Iterating ObjectId:
oid: 679d37953919f841b50f9710
gc_collect_cycles: 0
object(MongoDB\BSON\ObjectId)#1 (1) {
  ["oid"]=>
  string(24) "679d37953919f841b50f9710"
}
Iterating ObjectId:

In my local testing, each var_dump() results in a call to php_phongo_objectid_get_properties_hash with is_temp=1, which is expected.

I also observed that php_phongo_objectid_get_properties_hash was called three times for the initial foreach iteration (with is_temp=0). There are two invocations before printing the key/value pair and a third call after. On the second foreach after gc_collect_cycles(), php_phongo_objectid_get_properties_hash is never called. I don't have an explanation for this behavior, so I'll have to leave this issue open for the time being.

[jmikola]

Created PHPC-2505 to track this.