Page MenuHomePhabricator

Flow: DateTimeZone::__construct(): Unknown or bad timezone (+00:00)
Closed, ResolvedPublicPRODUCTION ERROR

Description

might be related to T159371

message:
DateTimeZone::__construct(): Unknown or bad timezone (+00:00)

stacktrace:
/srv/mediawiki/php-1.29.0-wmf.14/extensions/Echo/includes/model/Event.php:290, /srv/mediawiki/php-1.29.0-wmf.14/extensions/Echo/includes/model/Event.php:365, /srv/mediawiki/php-1.29.0-wmf.14/extensions/Echo/includes/model/Notification.php:162, /srv/mediawiki/php-1.29.0-wmf.14/extensions/Echo/includes/special/NotificationPager.php:53, /srv/mediawiki/php-1.29.0-wmf.14/extensions/Echo/includes/special/SpecialNotifications.php:41, /srv/mediawiki/php-1.29.0-wmf.14/includes/specialpage/SpecialPage.php:522, /srv/mediawiki/php-1.29.0-wmf.14/includes/specialpage/SpecialPageFactory.php:577, /srv/mediawiki/php-1.29.0-wmf.14/includes/MediaWiki.php:285, /srv/mediawiki/php-1.29.0-wmf.14/includes/MediaWiki.php:860, /srv/mediawiki/php-1.29.0-wmf.14/includes/MediaWiki.php:521, /srv/mediawiki/php-1.29.0-wmf.14/index.php:43, /srv/mediawiki/w/index.php:3

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

It seems to have come back as of wmf.14. I'm not seeing it in wmf.13

demon triaged this task as Unbreak Now! priority.Mar 1 2017, 8:30 PM

Change 340575 had a related patch set uploaded (by Catrope):
[mediawiki/extensions/Echo] Log more info for unserialize failures, and don't treat them as errors

https://gerrit.wikimedia.org/r/340575

Change 340575 merged by Catrope:
[mediawiki/extensions/Echo] Log more info for unserialize failures, and don't treat them as errors

https://gerrit.wikimedia.org/r/340575

Change 340588 had a related patch set uploaded (by Chad; owner: Catrope):
[mediawiki/extensions/Echo] Log more info for unserialize failures, and don't treat them as errors

https://gerrit.wikimedia.org/r/340588

Change 340588 merged by Chad:
[mediawiki/extensions/Echo] Log more info for unserialize failures, and don't treat them as errors

https://gerrit.wikimedia.org/r/340588

Catrope lowered the priority of this task from Unbreak Now! to Medium.Mar 2 2017, 12:25 AM

As far as I can tell, all cases of un-unserializable events are due to very old Flow events. Prior to rEFLWe5f75381274a: Serialize UUID into something more compact / T64532: Flow: serialize UUID objects as strings, the UUID class in Flow included an MWTimestamp object in its serialization, which in turn contains a DateTime object. This DateTime sometimes has its timezone set to +00:00, which causes an exception in HHVM but not in Zend(!). It took me a while to figure this out because of T146285: Switch mwscript from Zend PHP5 to default php alternative (e.g. HHVM or PHP7), which meant that unserializing the bad data failed in production but worked in mwscript eval.php. I noticed that it did fail on real app servers, and went down a version discrepancy rabbit hole, but it turns out that that was a red herring caused by my workaround for mwscript being unavailable on those machines, which ended up using HHVM (php) instead of Zend (php5).

The good news is we can write a script that runs a query like SELECT event_id, event_extra FROM echo_event WHERE event_type LIKE 'flow%' AND event_extra LIKE '%DateTime%', unserializes their event_extra blobs, serializes them again, and writes the new serialization back into the DB. Reserializing would work because the __sleep method introduced in rEFLWe5f75381274a: Serialize UUID into something more compact excludes the timestamp from the serialization.

Change 349716 had a related patch set uploaded (by Catrope):
[mediawiki/extensions/WikimediaMaintenance@master] Add maintenance script to reserialize old Flow notifications

https://gerrit.wikimedia.org/r/349716

Change 349716 merged by jenkins-bot:
[mediawiki/extensions/WikimediaMaintenance@master] Add maintenance script to reserialize old Flow notifications

https://gerrit.wikimedia.org/r/349716

Just as an example - after the script ran, betalabs enwiki has:

mysql> SELECT event_id, event_extra FROM echo_event WHERE event_type LIKE 'flow%' AND event_extra LIKE '%DateTime%'\G
*************************** 1. row ***************************
   event_id: 1490
event_extra: a:7:{s:11:"revision-id";O:15:"Flow\Model\UUID":3:{s:14:" * binaryValue";s:16:"
l?ޫ? ?>??";s:11:" * hexValue";s:32:"050a6cacdeabfd20ff1e02163e0fb68f";s:12:" * timestamp";O:11:"MWTimestamp":1:{s:9:"timestamp";O:8:"DateTime":3:{s:4:"date";s:19:"2013-11-27 20:06:10";s:13:"timezone_type";i:1;s:8:"timezone";s:6:"+00:00";}}}s:7:"post-id";O:15:"Flow\Model\UUID":3:{s:14:" * binaryValue";s:16:"
X?a???ʼn>92";s:11:" * hexValue";s:32:"050a58ac61a0eefec58902163e39327f";s:12:" * timestamp";N;}s:14:"topic-workflow";O:15:"Flow\Model\UUID":3:{s:14:" * binaryValue";s:16:"
X?a???ʼn>92";s:11:" * hexValue";s:32:"050a58ac61a0eefec58902163e39327f";s:12:" * timestamp";N;}s:11:"old-subject";s:31:"Title edited0.43375210531897535";s:11:"new-subject";s:30:"Title edited0.6070223512921361";s:10:"page_title";s:7:"Flow_QA";s:14:"page_namespace";i:1;}

Not done yet because I haven't run this script in production yet, and I don't want to do that during a deployment freeze week, so I'll do it next week.

Catrope claimed this task.

I've run the script in production. All events with problematic DateTime data have been reserialized, so we shouldn't see these errors again. Two events (one on mediawikiwiki and one on testwiki) had invalid extra blobs due to truncation. They were both very old (2013) and they were unrenderable anyway, so I just deleted them.

Change 448986 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[mediawiki/extensions/WikimediaMaintenance@master] Remove 'fixT159372.php' script

https://gerrit.wikimedia.org/r/448986

Change 448986 merged by jenkins-bot:
[mediawiki/extensions/WikimediaMaintenance@master] Remove 'fixT159372.php' script

https://gerrit.wikimedia.org/r/448986

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:10 PM