Edit report at https://bugs.php.net/bug.php?id=72011&edit=1
ID: 72011
User updated by: benjamin dot roth at jaumo dot com
Reported by: benjamin dot roth at jaumo dot com
Summary: DateTime serializes as empty object
Status: Open
Type: Bug
Package: Date/time related
Operating System: Linux
PHP Version: 7.0.5
Block user comment: N
Private report: N
New Comment:
@atkinson:
As you mention high load: I also recognized this misbehaviour only when the system was under
abnormal high load.
Previous Comments:
------------------------------------------------------------------------
[2016-04-27 09:27:40] atkinson dot d at mac dot com
We've seen this on a number of PHP major versions including 5.4, 5.6 & 7
This seems to occur randomly but in the past we've seen a definite correlation between high
server load and frequency of occurrence. At those times it was often a process unrelated to PHP or
Apache that was straining the server so the increase in errors was not simply due to an increased
number of requests.
I've added some additional logging to our serialisation code which I've included below.
I've also included a log snippet from the most recent occurrence.
This particular incident happened on a Linux box running PHP 7.0.0.
One thing that's strange in the log extract is when we serialise the entire object (which
contains an array that contains DateTimes) the DateTime object gets serialised as
'O:8:"DateTime":0:{}' however when we attempt to serialise that DateTime object
directly it just returns a reference number (e.g. 'r:530'). Not sure if this is a side
effect of the way I'm printing them.
static private function print_dates($data, $path = ''){
foreach ($data as $k => $v){
if (is_array($v)) self::print_dates($v, "$path.$k");
if (!($v instanceof DateTime)) continue;
log_message("*** ser $path.$k = " . @serialize($v));
log_message("*** print $path.$k = " . print_r($v, true));
log_message("*** format $path.$k = " . $v->format('r'));
log_message("*** time $path.$k = " . $v->getTimestamp());
log_message("******");
}
}
public function serialize() {
$data = get_object_vars($this);
unset($data['_relationships']);
$ser = @serialize($data);
if (strpos($ser, 'O:8:"DateTime":0:{}') !== false) {
$class_name = get_class();
log_message("*** Bad serialization: $class_name : $ser");
self::print_dates($data, $class_name);
}
return $ser;
}
2016-04-27 09:47:21 *** Bad serialization: ModelObject :
a:3:{s:4:"_vnc";b:0;s:16:"_fetched_columns";a:6:{s:2:"ID";s:3:"650";s:10:"CREATED_AT";O:8:"DateTime":0:{}s:13:"CREATED_BY_ID";s:3:"179";s:11:"MODIFIED_AT";O:8:"DateTime":0:{}s:14:"MODIFIED_BY_ID";s:3:"179";s:4:"NAME";s:9:"X.X.
Xxxx";}s:16:"_changed_columns";a:0:{}}
2016-04-27 09:47:21 *** ser ModelObject._fetched_columns.CREATED_AT = r:530;
2016-04-27 09:47:21 *** print ModelObject._fetched_columns.CREATED_AT = DateTime Object\n(\n)\n
2016-04-27 09:47:21 *** format ModelObject._fetched_columns.CREATED_AT = Thu, 25 Jul 2013 23:12:08
+0100
2016-04-27 09:47:21 *** time ModelObject._fetched_columns.CREATED_AT = 1374790328
2016-04-27 09:47:21 ******
2016-04-27 09:47:21 *** ser ModelObject._fetched_columns.MODIFIED_AT = r:532;
2016-04-27 09:47:21 *** print ModelObject._fetched_columns.MODIFIED_AT = DateTime Object\n(\n)\n
2016-04-27 09:47:21 *** format ModelObject._fetched_columns.MODIFIED_AT = Thu, 25 Jul 2013 23:12:08
+0100
2016-04-27 09:47:21 *** time ModelObject._fetched_columns.MODIFIED_AT = 1374790328
2016-04-27 09:47:21 ******
------------------------------------------------------------------------
[2016-04-12 13:52:32] benjamin dot roth at jaumo dot com
Description:
------------
I recognize occasionally that DateTime serializes as an empty object. Deserializing then throws a
fatal error with "Invalid serialization data for DateTime object"
Also print_r outputs the DateTime Object like
DateTime Object
(
)
This is the output of a real example when serializing an arbitrary structure with a DateTime object:
Serialize:
a:4:{s:6:"userId";i:27008573;s:9:"longitude";d:1.5192019999999999;s:8:"latitude";d:48.432855000000004;s:4:"date";O:8:"DateTime":0:{}}
print_r:
Array
(
[userId] => 27008573
[longitude] => 1,519202
[latitude] => 48,432855
[date] => DateTime Object
(
)
)
Unfortunately I was not able to reproduce it reliably, I was only able to detect it, when it occured
in may be one of 100.000 requests. In our production environment this occurs frequently but I was
not able to track it down.
I noticed this behaviour only in FPM workers not in CLI. WHEN this bug occurs, the affected FPM
worker behaves wrong until it is respawned, also in following requests.
I know this information is very rough. I am happy to provide any more information that can help :)
Test script:
---------------
<?php
// This should only demontrate what happens, if bug occurs
// Bug is VERY flaky
$d = new DateTime();
print_r($d);
Expected result:
----------------
DateTime Object
(
[date] => 2016-04-12 13:35:15.000000
[timezone_type] => 3
[timezone] => UTC
)
Actual result:
--------------
DateTime Object
(
)
------------------------------------------------------------------------
--
Edit this bug report at https://bugs.php.net/bug.php?id=72011&edit=1