Page MenuHomePhabricator

Monolog processed log events have dates in $wgLocaltimezone rather than UTC
Closed, ResolvedPublic


@faidon pointed out on irc that he had seen log events on fluorine with dates in timezones other than UTC. I poked around a bit in the Monolog source and found that this is feature added in Monolog 1.12.0. Each log event gets a DateTime object that eventually is formatted to a string via DateTime::format(). Since Monolog 1.12.0 these events are explicitly cast into the timezone returned by date_default_timezone_get().

At this point I'm not exactly sure where in the wiki startup cycle we use $wgLocaltimezone to set the timezone, but it certainly happens:

bd808$ mwscript eval.php enwiki
> echo date_default_timezone_get();

bd808$ mwscript eval.php barwiki
> echo date_default_timezone_get();

We need to find a way to control the behavior of Monolog to allow us to force the log event DateTimes into UTC.

Event Timeline

bd808 raised the priority of this task from to Needs Triage.
bd808 updated the task description. (Show Details)
bd808 added a project: MediaWiki-Debug-Logger.
bd808 added subscribers: bd808, faidon.
faidon triaged this task as High priority.May 20 2015, 5:34 PM
faidon added a project: Scrum-of-Scrums.
faidon set Security to None.

I think we are going to have to submit a patch upstream to Monolog to fix this. When we have a working patch we can cherry-pick it into mediawiki/vagrant.git until there is an upstream release that supports our feature. Luckily we thought about this when we drafted the rules for using Composer at WMF.

The upstream patch I made has been merged as with a small API change as a followup in

It would be trivial to backport this change to a fork but if we can wait a bit longer on this it seems likely that upstream will release an official version that includes the patch and then we can close out T99498 as well by upgrading.

Monolog 1.14.0 has been released which includes my patch to allow us to control the timezone.

Change 220781 had a related patch set uploaded (by BryanDavis):
Upgrade Monolog to v1.14.0

Change 220784 had a related patch set uploaded (by BryanDavis):
logging: Force Monolog logger timezone to UTC

Change 220781 merged by jenkins-bot:
Upgrade Monolog to v1.14.0

Change 220784 merged by jenkins-bot:
logging: Force Monolog logger timezone to UTC

The config change needed for this is live and the Monolog change needed to work with it will ride the train with 1.26wmf12 which should start hitting the wikis on 2015-06-30.

This change is on all wikis now and seems to be working as intended. I used grep -C 1 hewiki /a/mw-log/CentralAuth.log to check logs on fluorine and visually confirmed that the timestamps on the hewiki ($wgLocaltimezone = 'Asia/Tel_Aviv') events fit chronologically with the surrounding events. In log samples from prior to the 1.26wmf12 changes timestamps for hewiki are 3 hours ahead of UTC.