PHP memory corruption? Letters are --1

Screenshot because the text is a bit hard to read there

Also when creating a gallery... After saving the settings:

*Notice*: Undefined index: sort_orddr in */usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php* on line *125* *Notice*: Trying to get property of non-object in */usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php* on line *125* *Notice*: Undefined index: sort_orddr in */usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage/midgard.php* on line *58* *Notice*: Undefined index: sort_orddr in */usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage/midgard.php* on line *111* Server Error Missing field in object: midcom_db_topic Error 500

Screenshot also from the Gallery case

Oh, and SELinux has been ruled out. These errors happen also when SELinux is not enforcing (same as disabled).

I have the same problem on a Debian server when uploading to a o.r.gallery or photostream. I get notices abut an unknown field photograoher. The strange thing is that it happens just on one of the databases, on the other it works normally.

<jval> yes, it's definitely that line: $data = $types[$name]->convert_to_storage();
<jval> before it, echo $name prints: published
<jval> after it, echo $name prints: publishec

That convert_to_storage() method is executed in the first case from: midcom/lib/midcom/helper/datamanager2/type/date.php

<jval> return $this->value->getTime();
<jval> it's that line in midcom/lib/midcom/helper/datamanager2/type/date.php
<jval> line 128

Weird... If I change that line 128 from midcom/lib/midcom/helper/datamanager2/type/date.php from...

return $this->value->getTime();

to...

echo $this->name; return 0;

...it prints "published" and then I get the same error. So the change seems to happen when returning. It doesn't even seem to matter what is returned...

This seems to be a really internal issue... Like Piotras said, a pure hell issue...

I also tried to make the method not return anything (returns void eventually but not by php code). Guess what? The same issue happens also then. :)

So this is not a Midgard issue at all I guess. It's a PHP issue. I guess next we should try to see if it's the PHP version itself or one of the patches...

After the whole day of debugging I figured this out:

1. Segfault (if happens) happens in core's mgdschema's set_parameter function. Basically, memory is 100% corrupted on php-midgard level and we get (randomly) NULL string (php-midgard doesn't support NULL strings).

2. Problem doesn't happen when on_store_data callback is not executed.

3. Pointer seems to be moved also forward. In my latest case I got 'tagt' from 'tags'. So it clearly ++1.

(In [20487]) Check against NULL value. refs #804

So PHP 5.2.8 + two patches (php-4.3.3-install.patch + php-5.0.2-phpize64.patch) works on CentOS 5.2 while the default PHP package (5.1.6-20.el5_2.1) doesn't. Hope this information helps. :)

PHP 5.2.5 also works on CentOS 5.2.

The issue doesn't happen on CentOS 5.2 when PHP 5.2.0 is built with this spec

So PHP 5.2.0 + three patches (php-4.3.3-install.patch + php-5.0.4-norpath.patch + php-5.0.2-phpize64.patch) works on CentOS 5.2 while the default PHP package (5.1.6-20.el5_2.1) doesn't. So 5.1.6 doesn't work and the next version after it does work. Hope this information helps. :)

I downgraded midgard-core, mod_midgard and php-midgard to thor (1.8.9/1.8.9.1), but got this error:

Warning: (pid:26889): QUERY FAILED: Unknown column 'topic.created' in 'field list' QUERY: SELECT topic.guid, topic.sitegroup, topic.metadata_creator, NULLIF(topic.metadata_created,'0000-00-00 00:00:00') AS metadata_created, topic.metadata_revisor, NULLIF(topic.metadata_revised,'0000-00-00 00:00:00') AS metadata_revised, topic.metadata_revision, topic.metadata_locker, NULLIF(topic.metadata_locked,'0000-00-00 00:00:00') AS metadata_locked, topic.metadata_approver, NULLIF(topic.metadata_approved,'0000-00-00 00:00:00') AS metadata_approved, topic.metadata_authors, topic.metadata_owner, NULLIF(topic.metadata_schedule_start,'0000-00-00 00:00:00') AS metadata_schedule_start, NULLIF(topic.metadata_schedule_end,'0000-00-00 00:00:00') AS metadata_schedule_end, topic.metadata_hidden, topic.metadata_nav_noentry, topic.metadata_size, topic.metadata_published, NULLIF(topic.metadata_exported,'0000-00-00 00:00:00') AS metadata_exported, NULLIF(topic.metadata_imported,'0000-00-00 00:00:00') AS metadata_imported,topic.metadata in /usr/share/pear/midcom/lib/midcom/core/dbaobject.php on line 65

Fatal error: Class 'midgard_connection' not found in /usr/share/pear/midcom/lib/midcom/application.php on line 378

Midgard CMS Ragnaroek doesn't run on top of Midgard Thor I guess, so it's not possible to test if this issue happens also with previous Midgard versions.

At this point I think it just has to be PHP itself having a bug in 5.1 which was fixed in 5.2. Perhaps the solution to this issue is to claim that Midgard needs PHP >= 5.2...

Replying to piotras:

(In [20487]) Check against NULL value. refs #804

I just tried with midgard-core tarball taken from ragnaroek-dev OBS. No change. The same issue still happens.

You might be having a bit different issues on Debian. It might be another issue and not the same as what I've described happening on CentOS 5.2 with php-5.1.6-20.el5_2.1.

The issue I've experienced with php-5.1.6-20.el5_2.1 seems to only go away after upgrading PHP to 5.2 or newer.

<jval> the issue happens when php is returning a value from an object - and it happens even when it's returning void
<jval> midgard doesn't do anything there i guess unless it's attached some magic functionality to every return
<jval> so unless the midgard php extension has touched some php internals regarding returns, it must be php itself which has this bug

I think I've looked at the wrong place so far...

$types[$name]->convert_to_storage();

That line makes $name to change its value from "publishec" to "published", but that doesn't mean the problem has to be in convert_to_storage().

Perhaps that means that either $types or its subobject is corrupted. I guess when you use an internally corrupted object, anything can happen (like other objects/variables changing their values - like $name changing its value from "published" to "publishec").

So... I think we need to examine how $types and its subobjects are constructed. Perhaps memory starts to corrupt already there...

This doesn't change the fact that it doesn't happen with PHP 5.2, but perhaps finding the exact triggering line of code helps...

That line makes $name to change its value from "publishec" to "published"

:) I naturally ment to say from "published" to "publishec" there.

Anyway... It seems to be quite hard to test if $types is constructed without memory corruption... I'm not sure how much I want to spend time on this issue anymore. Perhaps we should just declare that Midgard needs PHP >= 5.2 and e.g. put php-5.2.x to OBS for distros with older php packages... :)

and e.g. put php-5.2.x to OBS for distros with older php packages...

Well that's not really possible at all (OBS builds packages with what it has + we would need to ship all php-* packages which is basically not possible)... So unless we get Midgard to work with PHP 5.1, users of el5 need to grab php-* packages from Fedora I guess... (Unless el5 upgrades to PHP 5.2, but that's not possible without requesting it with reasoning.)

Changed:

            $data = $types[$name]->convert_to_storage();

to:

            echo $name; echo ": ";
            $data = $types[$name]->convert_to_storage();
            echo gettype($data); echo " "; var_dump($data); echo "<br>";

Results:

schedulestart: integer int(0)
scheduleend: integer int(0)
navnoentry: integer int(0)
score: string string(0) ""
hidden: integer int(0)
description: string string(7) "testing"
keywords: string string(0) ""
tags: NULL NULL
published: integer int(1235257131)

Notice: Undefined index: publishec in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php on line 127

Is it normal that the property "tags" is NULL even if I try to write something to that field in the admin interface? Because if not, perhaps that's the first sign of memory corruption...

It's not possible that el5 would upgrade php to 5.2 because that would break abi compatibility. But they told me that they're going to backport memory corruption fixes from upstream, so it's possible that the php package will be fixed.

Another possible fix to this issue is that Piotras finds a way to go round the bugs of php < 5.2... :)

Tried convert_to_raw() before convert_to_storage() as mashiara suggested:

schedulestart: integer int(0)
scheduleend: integer int(0)
navnoentry: integer int(0)
score: string string(0) ""
hidden: integer int(0)
description: string string(10) "testing..."
keywords: string string(0) ""
tags: array array(1) { ["testi"]=> string(0) "" }
published: integer int(1235257131)

Notice: Undefined index: publishec in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php on line 127

Fatal error: Call to a member function convert_to_storage() on a non-object in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php on line 127

Notice how it says non-object there. That tells us that the object is corrupted I think.

:) Well that tells us nothing new because naturally $name has changed its value there and we're using the wrong array key there...

Commenting "tags" out from metadata "fixes" this issue:

<jval> mashiara: i tried convert_to_raw() and it seemed to return valid results, so i still don't see any corruption before suddenly everything breaks on return (everything is fine and then when control returns from convert_to_storage() hell gets loose :))
<mashiara> it might be that the tags datatype triggers the corruption, if you remove tags from the metadata schema what happens ?
<jval> that's a new idea :) well i guess we can test...
<jval> so... metadata schema is where...
<jval> it's lib/midcom/config/metadata_default.inc i guess
<jval> wow
<jval> mashiara: you were right!
<jval> save went through just fine - no errors

It's method convert_to_storage() in lib/midcom/helper/datamanager2/type/tags.php where the issue happens. Memory is just fine before that, and after that method has been executed memory starts to corrupt. The triggering code is there in that method. (Not saying the PHP code is faulty, but it does something which php-midgard or PHP internals don't like. :))

No... I tried to put "return NULL;" there and I still get the error. Does that mean $typestags? is corrupted when constructed?

$types["tags"]

That object is somehow corrupted, but it's not its initialization in itself which makes variables to change their values.

$types["tags"]->convert_to_storage();

That operation causes this issue. Still... If I put "return NULL;" into the first line of that method, I still get the error. So... The object is corrupted, but it's when its method gets called when things break.

If I exclude "tags" like this:

        if ($name != "tags" ) {
            $data = $types[$name]->convert_to_storage();
            if ($type_definition['storage']['location'] !== null)
            {
             	if ($types[$name]->serialized_storage)
               	{
                    $data = serialize($data);
                }
               	$this->_on_store_data($name, $data);
            }
        }

...I don't see errors.

(In [20636]) Do not use predefined return_value named variable explicitly. refs #804. Zend may reallocate such pointer.

I tested php-midgard with the changes made in commit 20636:

Warning: Invalid argument supplied for foreach() in /usr/share/pear/midcom/lib/midcom/baseclasses/core/dbobject.php on line 1530

Notice: Undefined index: publishec in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php on line 125

Notice: Trying to get property of non-object in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage.php on line 125

Notice: Undefined index: publishec in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage/midgard.php on line 58

Notice: Undefined index: publishec in /usr/share/pear/midcom/lib/midcom/helper/datamanager2/storage/midgard.php on line 111

The commit didn't fix this issue, but brought a new issue (Invalid argument supplied for foreach()). The new issue causes warnings also on the front page (basically every MidCOM powered page has the warnings)... I guess you should revert the commit? :)

(In [20643]) Return array via return_value explicitly. refs #804.

Replying to piotras:

(In [20643]) Return array via return_value explicitly. refs #804.

The new warnings are now gone, but the issue remains. At least the issue with el5's php package. I don't know about the issues on Debian as I haven't seen them myself. (Haven't tested on Debian for a while though.)

Casting to string "fixes" the first case (page --> edit metadata --> save)

That "fixes" the first case:

-            $data = $types[$name]->convert_to_storage();
+            $data = (string)$types[$name]->convert_to_storage();

Does this information help us? :)

Yay! Works now!

Serious? A commit fixing this coming? I think I need to test it first if you really think you managed to find a way to fix it.

Or were you just being sarcastic? :)

I attached php_midgard_gobject_generic.c file with debug statements added for read and write property hook. A few also added to gvalue<->zval conversion routines. To test, download this file to php-midgard sources and recompile. Then in MidCOM in storage.php file:

midgard_connection::set_log_level("debug");
$data = $types[$name]->convert_to_storage();
midgard_connection::set_log_level("warning");

And request page. Debug statements will be written to Apache error log file (or to the vhost's one). Main point of this operation is to find out if zval pointer is not overwritten anywhere.

We have interesting debug statements:

midgard-core (pid:31749):(info): midgard_collector::get_subkey(...)
midgard-core (pid:31749):(debug):GET_SUBKEY INITIALIZE ZVAL: 0xbfdb0da0
midgard-core (pid:31749):(debug):GVALUE TO ZVAL: 0x921307c
midgard-core (pid:31749):(info): midgard_collector::get_subkey(...)
midgard-core (pid:31749):(debug):GET_SUBKEY INITIALIZE ZVAL: 0xbfdb0da0
midgard-core (pid:31749):(debug):GVALUE TO ZVAL: 0x921307c
midgard-core (pid:31749):(info): midgard_collector::get_subkey(...)
midgard-core (pid:31749):(debug):GET_SUBKEY INITIALIZE ZVAL: 0xbfdb0da0
midgard-core (pid:31749):(debug):GVALUE TO ZVAL: 0x921307c

I think problem is related to fact how Zend engine allocated memory for PHP variables. Also above logs clearly shows this bug is related to #717.

Also, I have interesting valgrind logs, from machine which might be affected by this bug:

==16228== Source and destination overlap in memcpy(0x72120B0, 0x72120B0, 5)
==16228==    at 0x401EC66: memcpy (mc_replace_strmem.c:116)
==16228==    by 0x4F766B2: _estrndup (in /usr/lib/apache2/modules/libphp5.so)
==16228==    by 0x4F7D7F2: zend_do_receive_arg (in /usr/lib/apache2/modules/libphp5.so)
==16228==    by 0x4F6DE71: zendparse (in /usr/lib/apache2/modules/libphp5.so)
==16228==    by 0x4F6F52F: compile_file (in /usr/lib/apache2/modules/libphp5.so)

Added possible get_subkey fix in r20663

Tested the latest tarballs from ragnaroek-dev OBS repository... No change. Page --> Edit medatada --> Save still gives me this: http://trac.midgard-project.org/attachment/ticket/804/screenshot.png

<jval> Piotras: running /midcom-exec-org.routamc.positioning/import-countries.php
<jval> Importing Andorra...
<jval> Warning: (pid:4101): zval2gvalue conversion failed in /usr/share/pear/midcom/lib/midcom/core/querybuilder.php on line 750
<jval> MGD_ERR_OK
<jval> etc.
<jval> Piotras: this is quite recent ragnaroek-dev from obs

it's most likely because of some commit regarding #804 :)

If possible, the Debian related issue should be tested using the latest PHP 5.2.9 which just got released:

http://www.php.net/releases/5_2_9.php

http://www.php.net/ChangeLog-5.php#5.2.9

Notice that there are many memory related fixes in that release of PHP.

Doing a fresh install:

<jval> Midgard domain (sitegroup) name ? (default: 'localhost')[ Available: none]:
<jval> PHP Warning:  in_array(): Wrong datatype for second argument in /usr/share/midgard/setup/php/midgard_setup_wizard.php on line 62

<jval> midgard_sitegroup::list_names(); <-- perhaps that used to return something and now it doesn't
<jval> i bet this is related to recent php-midgard commits - that method is in php-midgard

Piotras please see which one should be fixed there. I think (not sure, but it's probable) that:

$sg_array = midgard_sitegroup::list_names();

...used to return an empty array at least and now it returns NULL or something like that (not an array at least). That's why PHP warns about $sg_array not being an array when used in in_array() call later.

Is it correct that midgard_sitegroup::list_names() doesn't return an array in this case? If it is correct, then we need to change the PHP code in midgard-data's midgard_setup_wizard.php. If it's not correct, php-midgard's midgard_sitegroup::list_names() method should be fixed.

I've not taken the latest version of php-midgard from ragnaroek-dev OBS repo, but it's quite recent (from yesterday or day before).

Issue is the same with PHP 5.2.9. However memory seems to be corrupted differently. Before property became ')' and now again: 'photographer' became 'photograoher'.

Replying to jval:

{{{ $sg_array = midgard_sitegroup::list_names(); }}} ...used to return an empty array at least and now it returns NULL

that is fixed and not related to this issue

I disabled all functions which free memory blocks or destroy zend variables in midgard extension and recompiled. Didn't help. Issue is still the same, so 100% it's not midgard-php which could for example trigger double free/delete.

(In [20713]) _on_store_data: return if given data is null, refs #804

Replying to piotras:

(In [20713]) _on_store_data: return if given data is null, refs #804

This commit seems to workaround issue.

Replying to piotras:

Replying to piotras:

(In [20713]) _on_store_data: return if given data is null, refs #804

This commit seems to workaround issue.

o.r.gallery upload works for me now without error as well!

Confirmed. The MidCOM level workaround indeed works - even with PHP < 5.2.

Because the workaround works, it must be this line:

$this->object->metadata->$name = $data;

in branches/ragnaroek/midcom/midcom.helper.datamanager2/storage/midgard.php line 112 (rev 20713).

For example when "tags" metadata is enabled and its value is NULL, this issue happens (when there's no workaround on midcom level).

So it seems that when $this->object->metadata->$name = NULL is executed, memory corrupts.

Piotras told me at #midgard, that on C level these actions happen on object->metadata->property = value:

1. there's metadata object in question (zend thing)

2. set property

3. there's a hook so use it (midgard thing)

4. get value (as zval) and create new GValue (midgard thing)

5. Set GObject property (midgard thing)

6. invoke zend's property write routine (zend thing)

Those six should be debugged because the issue should happen at one of those. This can be a PHP bug in the end, but I think if the issue happens there, we might be able to find the actual Zend level call where the problem lies.

So perhaps the issue happens at some point in 1-6 when NULL is assigned. Perhaps the NULL value makes some pointers to do something wrong...

(01:27:47) jval: i think i understand now what Piotras tried to told me
(01:28:02) jval: we already debugged that part basically
(01:28:33) jval: and we didn't see anything behaving differently in different situations
(01:29:29) jval: there was some weird reusage of memory addresses, but iirc that was happening also when no memory corruption was occuring...
(01:29:48) jval: so we've not necessarily made progress...
(01:31:14) jval: i'm not sure though because i don't remember it that well... (was the memory addressing weird always or just when the issue was on) :)

(In [20725]) parameter method: Do not convert given zval to string. Insteas, create new GValue and transform it to string type. refs #804

Replying to piotras:

(In [20725]) parameter method: Do not convert given zval to string. Insteas, create new GValue and transform it to string type. refs #804

This should fix the issue. Problem seems to be with zval holding null and being converted to string in one step of some loop.

I removed the MidCOM level workaround and tested midgard-core and php-midgard from svn revision 20725.

Fix confirmed! Good job!!! :)

So is that convert_to_string_ex(&zvalue); a buggy Zend call?

Do you have any theory why in my case an upgrade to PHP 5.2.0 helped? Is it possible that PHP 5.2.0 introduced some (perhaps partial, but anyway) fix for that call? I'm asking because it would be great if we could provide information to el5 maintainers about which kind of fixes from PHP >= 5.2 should be backported... :)

Anyway, great that this finally works! In my opinion, this ticket is now fixed and can be closed.

I think we opened some pandora's box using convert_to_string. I think simple PHP code which triggers it looks like this:

$clct = array('a', 'b', 1, 2, 'c', null, 4, 5, 'd', null);

foreach ($clct as $k => $v)
{
    $data = $clct[$k];
    $mgdschema_obj->parameter("a", "b", $data); /* implicit convert_to_string(data_zval) */

}

There are also interesting statistics:

implicit convert_to_yxc calls in php-midgard extension (legacy incl) : 696 implicit convert_to_xyc calls in mgdschema bindings : 11

By implicit I mean, such calls which are invoked internally and user is not informed about conversion.

I close ticket. If you find it important, re open it.