Page Menu
Home
Phabricator
Search
Configure Global Search
Log In
Files
F15367171
D20566.diff
No One
Temporary
Actions
View File
Edit File
Delete File
View Transforms
Subscribe
Mute Notifications
Award Token
Flag For Later
Size
10 KB
Referenced Files
None
Subscribers
None
D20566.diff
View Options
diff --git a/src/applications/herald/adapter/HeraldAdapter.php b/src/applications/herald/adapter/HeraldAdapter.php
--- a/src/applications/herald/adapter/HeraldAdapter.php
+++ b/src/applications/herald/adapter/HeraldAdapter.php
@@ -130,6 +130,14 @@
abstract public function getHeraldName();
+ final public function willGetHeraldField($field_key) {
+ // This method is called during rule evaluation, before we engage the
+ // Herald profiler. We make sure we have a concrete implementation so time
+ // spent loading fields out of the classmap is not mistakenly attributed to
+ // whichever field happens to evaluate first.
+ $this->requireFieldImplementation($field_key);
+ }
+
public function getHeraldField($field_key) {
return $this->requireFieldImplementation($field_key)
->getHeraldFieldValue($this->getObject());
diff --git a/src/applications/herald/controller/HeraldTranscriptController.php b/src/applications/herald/controller/HeraldTranscriptController.php
--- a/src/applications/herald/controller/HeraldTranscriptController.php
+++ b/src/applications/herald/controller/HeraldTranscriptController.php
@@ -77,6 +77,7 @@
$this->buildTransactionsTranscriptPanel(
$object,
$xscript),
+ $this->buildProfilerTranscriptPanel($xscript),
);
}
@@ -597,4 +598,98 @@
}
+ private function buildProfilerTranscriptPanel(HeraldTranscript $xscript) {
+ $viewer = $this->getViewer();
+
+ $object_xscript = $xscript->getObjectTranscript();
+
+ $profile = $object_xscript->getProfile();
+
+ // If this is an older transcript without profiler information, don't
+ // show anything.
+ if ($profile === null) {
+ return null;
+ }
+
+ $profile = isort($profile, 'elapsed');
+ $profile = array_reverse($profile);
+
+ $phids = array();
+ foreach ($profile as $frame) {
+ if ($frame['type'] === 'rule') {
+ $phids[] = $frame['key'];
+ }
+ }
+ $handles = $viewer->loadHandles($phids);
+
+ $field_map = HeraldField::getAllFields();
+
+ $rows = array();
+ foreach ($profile as $frame) {
+ $cost = $frame['elapsed'];
+ $cost = 1000000 * $cost;
+ $cost = pht('%sus', new PhutilNumber($cost));
+
+ $type = $frame['type'];
+ switch ($type) {
+ case 'rule':
+ $type_display = pht('Rule');
+ break;
+ case 'field':
+ $type_display = pht('Field');
+ break;
+ default:
+ $type_display = $type;
+ break;
+ }
+
+ $key = $frame['key'];
+ switch ($type) {
+ case 'field':
+ $field_object = idx($field_map, $key);
+ if ($field_object) {
+ $key_display = $field_object->getHeraldFieldName();
+ } else {
+ $key_display = $key;
+ }
+ break;
+ case 'rule':
+ $key_display = $handles[$key]->renderLink();
+ break;
+ default:
+ $key_display = $key;
+ break;
+ }
+
+ $rows[] = array(
+ $type_display,
+ $key_display,
+ $cost,
+ pht('%s', new PhutilNumber($frame['count'])),
+ );
+ }
+
+ $table_view = id(new AphrontTableView($rows))
+ ->setHeaders(
+ array(
+ pht('Type'),
+ pht('What'),
+ pht('Cost'),
+ pht('Count'),
+ ))
+ ->setColumnClasses(
+ array(
+ null,
+ 'wide',
+ 'right',
+ 'right',
+ ));
+
+ $box_view = id(new PHUIObjectBoxView())
+ ->setHeaderText(pht('Profile'))
+ ->setTable($table_view);
+
+ return $box_view;
+ }
+
}
diff --git a/src/applications/herald/engine/HeraldEngine.php b/src/applications/herald/engine/HeraldEngine.php
--- a/src/applications/herald/engine/HeraldEngine.php
+++ b/src/applications/herald/engine/HeraldEngine.php
@@ -16,6 +16,9 @@
private $forbiddenActions = array();
private $skipEffects = array();
+ private $profilerStack = array();
+ private $profilerFrames = array();
+
public function setDryRun($dry_run) {
$this->dryRun = $dry_run;
return $this;
@@ -137,7 +140,8 @@
->setName($object->getHeraldName())
->setType($object->getAdapterContentType())
->setFields($this->fieldCache)
- ->setAppliedTransactionPHIDs($xaction_phids);
+ ->setAppliedTransactionPHIDs($xaction_phids)
+ ->setProfile($this->getProfile());
$this->transcript->setObjectTranscript($object_transcript);
@@ -329,7 +333,36 @@
break;
}
- $match = $this->doesConditionMatch($rule, $condition, $object);
+ // Here, we're profiling the cost to match the condition value against
+ // whatever test is configured. Normally, this cost should be very
+ // small (<<1ms) since it amounts to a single comparison:
+ //
+ // [ Task author ][ is any of ][ alice ]
+ //
+ // However, it may be expensive in some cases, particularly if you
+ // write a rule with a very creative regular expression that backtracks
+ // explosively.
+ //
+ // At time of writing, the "Another Herald Rule" field is also
+ // evaluated inside the matching function. This may be arbitrarily
+ // expensive (it can prompt us to execute any finite number of other
+ // Herald rules), although we'll push the profiler stack appropriately
+ // so we don't count the evaluation time against this rule in the final
+ // profile.
+
+ $caught = null;
+
+ $this->pushProfilerRule($rule);
+ try {
+ $match = $this->doesConditionMatch($rule, $condition, $object);
+ } catch (Exception $ex) {
+ $caught = $ex;
+ }
+ $this->popProfilerRule($rule);
+
+ if ($caught) {
+ throw $ex;
+ }
if (!$all && $match) {
$reason = pht('Any condition matched.');
@@ -421,7 +454,25 @@
public function getObjectFieldValue($field) {
if (!array_key_exists($field, $this->fieldCache)) {
- $this->fieldCache[$field] = $this->object->getHeraldField($field);
+ $adapter = $this->object;
+
+ $adapter->willGetHeraldField($field);
+
+ $caught = null;
+
+ $this->pushProfilerField($field);
+ try {
+ $value = $adapter->getHeraldField($field);
+ } catch (Exception $ex) {
+ $caught = $ex;
+ }
+ $this->popProfilerField($field);
+
+ if ($caught) {
+ throw $caught;
+ }
+
+ $this->fieldCache[$field] = $value;
}
return $this->fieldCache[$field];
@@ -637,4 +688,98 @@
return $is_forbidden;
}
+/* -( Profiler )----------------------------------------------------------- */
+
+ private function pushProfilerField($field_key) {
+ return $this->pushProfilerStack('field', $field_key);
+ }
+
+ private function popProfilerField($field_key) {
+ return $this->popProfilerStack('field', $field_key);
+ }
+
+ private function pushProfilerRule(HeraldRule $rule) {
+ return $this->pushProfilerStack('rule', $rule->getPHID());
+ }
+
+ private function popProfilerRule(HeraldRule $rule) {
+ return $this->popProfilerStack('rule', $rule->getPHID());
+ }
+
+ private function pushProfilerStack($type, $key) {
+ $this->profilerStack[] = array(
+ 'type' => $type,
+ 'key' => $key,
+ 'start' => microtime(true),
+ );
+
+ return $this;
+ }
+
+ private function popProfilerStack($type, $key) {
+ if (!$this->profilerStack) {
+ throw new Exception(
+ pht(
+ 'Unable to pop profiler stack: profiler stack is empty.'));
+ }
+
+ $frame = last($this->profilerStack);
+ if (($frame['type'] !== $type) || ($frame['key'] !== $key)) {
+ throw new Exception(
+ pht(
+ 'Unable to pop profiler stack: expected frame of type "%s" with '.
+ 'key "%s", but found frame of type "%s" with key "%s".',
+ $type,
+ $key,
+ $frame['type'],
+ $frame['key']));
+ }
+
+ // Accumulate the new timing information into the existing profile. If this
+ // is the first time we've seen this particular rule or field, we'll
+ // create a new empty frame first.
+
+ $elapsed = microtime(true) - $frame['start'];
+ $frame_key = sprintf('%s/%s', $type, $key);
+
+ if (!isset($this->profilerFrames[$frame_key])) {
+ $current = array(
+ 'type' => $type,
+ 'key' => $key,
+ 'elapsed' => 0,
+ 'count' => 0,
+ );
+ } else {
+ $current = $this->profilerFrames[$frame_key];
+ }
+
+ $current['elapsed'] += $elapsed;
+ $current['count']++;
+
+ $this->profilerFrames[$frame_key] = $current;
+
+ array_pop($this->profilerStack);
+ }
+
+ private function getProfile() {
+ if ($this->profilerStack) {
+ $frame = last($this->profilerStack);
+ $frame_type = $frame['type'];
+ $frame_key = $frame['key'];
+ $frame_count = count($this->profilerStack);
+
+ throw new Exception(
+ pht(
+ 'Unable to retrieve profile: profiler stack is not empty. The '.
+ 'stack has %s frame(s); the final frame has type "%s" and key '.
+ '"%s".',
+ new PhutilNumber($frame_count),
+ $frame_type,
+ $frame_key));
+ }
+
+ return array_values($this->profilerFrames);
+ }
+
+
}
diff --git a/src/applications/herald/storage/transcript/HeraldObjectTranscript.php b/src/applications/herald/storage/transcript/HeraldObjectTranscript.php
--- a/src/applications/herald/storage/transcript/HeraldObjectTranscript.php
+++ b/src/applications/herald/storage/transcript/HeraldObjectTranscript.php
@@ -7,6 +7,7 @@
protected $name;
protected $fields;
protected $appliedTransactionPHIDs;
+ protected $profile;
public function setPHID($phid) {
$this->phid = $phid;
@@ -48,6 +49,15 @@
return $this->fields;
}
+ public function setProfile(array $profile) {
+ $this->profile = $profile;
+ return $this;
+ }
+
+ public function getProfile() {
+ return $this->profile;
+ }
+
public function setAppliedTransactionPHIDs($phids) {
$this->appliedTransactionPHIDs = $phids;
return $this;
File Metadata
Details
Attached
Mime Type
text/plain
Expires
Wed, Mar 12, 4:25 PM (1 w, 4 d ago)
Storage Engine
blob
Storage Format
Encrypted (AES-256-CBC)
Storage Handle
7367313
Default Alt Text
D20566.diff (10 KB)
Attached To
Mode
D20566: Add a basic profiler to Herald transcripts
Attached
Detach File
Event Timeline
Log In to Comment