Page MenuHomePhabricator

Add timing information for commit hooks to push logs
ClosedPublic

Authored by epriestley on Nov 6 2018, 10:59 PM.
Tags
None
Referenced Files
Unknown Object (File)
Fri, Dec 20, 6:43 PM
Unknown Object (File)
Fri, Dec 20, 6:42 PM
Unknown Object (File)
Fri, Dec 20, 6:42 PM
Unknown Object (File)
Thu, Dec 5, 12:33 PM
Unknown Object (File)
Wed, Dec 4, 7:01 AM
Unknown Object (File)
Sun, Dec 1, 3:55 PM
Unknown Object (File)
Sun, Dec 1, 3:55 PM
Unknown Object (File)
Sun, Dec 1, 3:55 PM
Subscribers
Restricted Owners Package

Details

Summary

Depends on D19779. Ref T13216. The push logs currently record the "hostWait", which is roughly "locking + subprocess cost". We also record locking separately, so we can figure out "subprocess cost" alone by subtracting the lock costs.

However, the subprocess (normally git receive-pack) runs hooks, and we don't have an easy way to figure out how much time was spent doing actual git stuff vs spent doing commit hook processing. This would have been useful in diagnosing at least one recent issue.

Track at least a rough hook cost and record it in the push logs.

Test Plan

Pushed to a repository, saw a reasonable hook cost appear in the database table.

Diff Detail

Repository
rP Phabricator
Lint
Lint Not Applicable
Unit
Tests Not Applicable

Event Timeline

Owners added a subscriber: Restricted Owners Package.Nov 6 2018, 10:59 PM
amckinley added inline comments.
src/applications/diffusion/engine/DiffusionCommitHookEngine.php
1123

I know this is a really trivial amount of code to factor out into a function, but I'm still surprised this isn't a libphutil function since we have this construction alllll over the place.

This revision is now accepted and ready to land.Nov 7 2018, 8:11 PM

I had a hard time coming up with a good name that made parameter order crystal clear (is it start, end in chronological order, or end, start in arithmetic x - y order?), and then thought that maybe we could return the absolute value and moot the question of order, but didn't love that. But I think it can just be phutil_microseconds_since($start_time) and avoid the question entirely. I'll throw a followup into the stack somewhere.

This revision was automatically updated to reflect the committed changes.