Page MenuHomePhabricator

Record late paint timing in navtiming
Closed, ResolvedPublic


It's possible that firstPaint may happen after the load event. Data suggests this could happen up to 5% of the time on mobile for browsers that support firstPaint. Let's find out by watching for last paint timings and reporting them in a new EventLogging schema.

Event Timeline

Gilles triaged this task as Medium priority.Jan 30 2019, 6:11 PM

Change 488016 had a related patch set uploaded (by Gilles; owner: Gilles):
[mediawiki/extensions/NavigationTiming@master] Record late paint timings

Change 488016 merged by jenkins-bot:
[mediawiki/extensions/NavigationTiming@master] Record late paint timings

No records yet in Hive. Either the code isn't working, or this situation never happens...

Looking in logstash, we're getting plenty of EventError occurrences with: None is not of type 'integer'

{"dt": "2019-02-25T02:00:35Z", "event": {"pageviewToken": "redacted", "startTime": null}, "ip": "redacted", "recvFrom": "cp5008.eqsin.wmnet", "revision": 18849693, "schema": "PaintTiming", "seqId": 14206806, "userAgent": {"browser_family": "Chrome", "browser_major": "62", "browser_minor": "0", "device_family": "Other", "is_bot": false, "is_mediawiki": false, "os_family": "Mac OS X", "os_major": "10", "os_minor": "13", "wmf_app_version": "-"}, "uuid": "redacted", "webHost": "", "wiki": "enwiki"}

So, something in the code isn't right, as "name" is missing altogether and startTime ends up being null...

Change 492607 had a related patch set uploaded (by Gilles; owner: Gilles):
[mediawiki/extensions/NavigationTiming@master] Fix observePaintTiming for loop

Change 492607 merged by jenkins-bot:
[mediawiki/extensions/NavigationTiming@master] Fix observePaintTiming for loop

Data is coming in:

Not super common, but it happens. From what I'm seeing glancing in Hive, the values aren't extreme. They seem to be happening shortly after the load event.

This probably won't change the global paint metrics all that much, but for the sake of correctness I think we should switch to collecting paint timing that way, with the "regular" firstPaint collection going to the new schema as well.