even more tracing

This commit is contained in:
Andrew Dolgov 2023-04-09 22:31:42 +03:00
parent e18295a364
commit fd5e0f98c4
No known key found for this signature in database
GPG Key ID: 1A56B4FA25D4AF2A
4 changed files with 33 additions and 44 deletions

View File

@ -2,6 +2,7 @@
class Digest
{
static function send_headlines_digests(): void {
$scope = Tracer::start(__METHOD__);
$user_limit = 15; // amount of users to process (e.g. emails to send out)
$limit = 1000; // maximum amount of headlines to include
@ -75,6 +76,8 @@ class Digest
}
}
}
$scope->close();
Debug::log("All done.");
}

View File

@ -49,12 +49,6 @@ class Feeds extends Handler_Protected {
const NEVER_GROUP_FEEDS = [ Feeds::FEED_RECENTLY_READ, Feeds::FEED_ARCHIVED ];
const NEVER_GROUP_BY_DATE = [ Feeds::FEED_PUBLISHED, Feeds::FEED_STARRED, Feeds::FEED_FRESH ];
/** @var int|float int on 64-bit, float on 32-bit */
private $viewfeed_timestamp;
/** @var int|float int on 64-bit, float on 32-bit */
private $viewfeed_timestamp_last;
function csrf_ignore(string $method): bool {
$csrf_ignored = array("index");
@ -281,8 +275,6 @@ class Feeds extends Handler_Protected {
array_push($topmost_article_ids, $id);
}
$this->_mark_timestamp(" labels");
$line["feed_title"] = $line["feed_title"] ?? "";
$button_doc = new DOMDocument();
@ -358,16 +350,12 @@ class Feeds extends Handler_Protected {
$line["enclosures"] = [ 'formatted' => '', 'entries' => [] ];
}
$this->_mark_timestamp(" enclosures");
$line["updated_long"] = TimeHelper::make_local_datetime($line["updated"],true);
$line["updated"] = TimeHelper::make_local_datetime($line["updated"], false, null, false, true);
$line['imported'] = T_sprintf("Imported at %s",
TimeHelper::make_local_datetime($line["date_entered"], false));
$this->_mark_timestamp(" local-datetime");
if ($line["tag_cache"])
$tags = explode(",", $line["tag_cache"]);
else
@ -377,14 +365,12 @@ class Feeds extends Handler_Protected {
//$line["tags"] = Article::_get_tags($line["id"], false, $line["tag_cache"]);
$this->_mark_timestamp(" tags");
$line['has_icon'] = self::_has_icon($feed_id);
//setting feed headline background color, needs to change text color based on dark/light
$fav_color = $line['favicon_avg_color'] ?? false;
$this->_mark_timestamp(" pre-color");
$c_scope = Tracer::start('colors');
require_once "colors.php";
@ -400,22 +386,16 @@ class Feeds extends Handler_Protected {
$line['feed_bg_color'] = 'rgba(' . implode(",", $rgba_cache[$feed_id]) . ',0.3)';
}
$this->_mark_timestamp(" color");
$this->_mark_timestamp(" pre-hook_render_cdm");
$c_scope->close();
PluginHost::getInstance()->chain_hooks_callback(PluginHost::HOOK_RENDER_ARTICLE_CDM,
function ($result, $plugin) use (&$line) {
$line = $result;
$this->_mark_timestamp(" hook: " . get_class($plugin));
},
$line);
$this->_mark_timestamp(" hook_render_cdm");
$line['content'] = DiskCache::rewrite_urls($line['content']);
$this->_mark_timestamp(" disk_cache_rewrite");
/* we don't need those */
foreach (["date_entered", "guid", "last_published", "last_marked", "tag_cache", "favicon_avg_color",
@ -430,8 +410,6 @@ class Feeds extends Handler_Protected {
$a_scope->close();
$this->_mark_timestamp("end of articles");
if (!$headlines_count) {
if ($result instanceof PDOStatement) {
@ -2503,23 +2481,5 @@ class Feeds extends Handler_Protected {
return [$query, $skip_first_id];
}
private function _mark_timestamp(string $label): void {
if (empty($_REQUEST['timestamps']))
return;
if (!$this->viewfeed_timestamp) $this->viewfeed_timestamp = hrtime(true);
if (!$this->viewfeed_timestamp_last) $this->viewfeed_timestamp_last = hrtime(true);
$timestamp = hrtime(true);
printf("[%4d ms, %4d abs] %s\n",
($timestamp - $this->viewfeed_timestamp_last) / 1e6,
($timestamp - $this->viewfeed_timestamp) / 1e6,
$label);
$this->viewfeed_timestamp_last = $timestamp;
}
}

View File

@ -344,6 +344,8 @@ class PluginHost {
foreach ($this->get_hooks((string)$hook) as $plugin) {
//Debug::log("invoking: " . get_class($plugin) . "->$hook()", Debug::$LOG_VERBOSE);
$p_scope = Tracer::start("$hook - " . get_class($plugin));
try {
if ($callback($plugin->$method(...$args), $plugin))
break;
@ -352,6 +354,8 @@ class PluginHost {
} catch (Error $err) {
user_error($err, E_USER_WARNING);
}
$p_scope->close();
}
$scope->close();
@ -444,7 +448,7 @@ class PluginHost {
$class = trim($class);
$class_file = strtolower(basename(clean($class)));
$p_scope = Tracer::start('load_plugin', ['file' => $class_file]);
$p_scope = Tracer::start("loading $class_file");
// try system plugin directory first
$file = dirname(__DIR__) . "/plugins/$class_file/init.php";
@ -507,6 +511,8 @@ class PluginHost {
_bind_textdomain_codeset($class, "UTF-8");
}
$i_scope = Tracer::start('init and register plugin');
try {
switch ($kind) {
case $this::KIND_SYSTEM:
@ -532,6 +538,8 @@ class PluginHost {
user_error($err, E_USER_WARNING);
}
$i_scope->close();
}
}
$p_scope->close();

View File

@ -68,6 +68,8 @@ class RSSUtils {
* @param array<string, false|string> $options
*/
static function update_daemon_common(int $limit = 0, array $options = []): int {
$scope = Tracer::start(__METHOD__);
if (!$limit) $limit = Config::get(Config::DAEMON_FEED_LIMIT);
if (Config::get_schema_version() != Config::SCHEMA_VERSION) {
@ -283,6 +285,8 @@ class RSSUtils {
// Send feed digests by email if needed.
Digest::send_headlines_digests();
$scope->close();
return $nf;
}
@ -349,6 +353,7 @@ class RSSUtils {
static function update_rss_feed(int $feed, bool $no_cache = false) : bool {
$scope = Tracer::start(__METHOD__, [], func_get_args());
Debug::log("start", Debug::LOG_VERBOSE);
$pdo = Db::pdo();
@ -383,16 +388,19 @@ class RSSUtils {
if ($user) {
if ($user->access_level == UserHelper::ACCESS_LEVEL_READONLY) {
Debug::log("error: denied update for $feed: permission denied by owner access level");
$scope->close();
return false;
}
} else {
// this would indicate database corruption of some kind
Debug::log("error: owner not found for feed: $feed");
$scope->close();
return false;
}
} else {
Debug::log("error: feeds table record not found for feed: $feed");
$scope->close();
return false;
}
@ -550,6 +558,7 @@ class RSSUtils {
$feed_obj->save();
}
$scope->close();
return $error_message == "";
}
@ -675,7 +684,7 @@ class RSSUtils {
]);
$feed_obj->save();
$scope->close();
return true; // no articles
}
@ -684,6 +693,8 @@ class RSSUtils {
$tstart = time();
foreach ($items as $item) {
$a_scope = Tracer::start('article');
$pdo->beginTransaction();
Debug::log("=================================================================================================================================",
@ -1276,6 +1287,7 @@ class RSSUtils {
Debug::log("article processed.", Debug::LOG_VERBOSE);
$pdo->commit();
$a_scope->close();
}
Debug::log("=================================================================================================================================",
@ -1317,10 +1329,12 @@ class RSSUtils {
unset($rss);
Debug::log("update failed.", Debug::LOG_VERBOSE);
$scope->close();
return false;
}
Debug::log("update done.", Debug::LOG_VERBOSE);
$scope->close();
return true;
}
@ -1485,6 +1499,8 @@ class RSSUtils {
* @return array<int, array<string, string>> An array of filter action arrays with keys "type" and "param"
*/
static function get_article_filters(array $filters, string $title, string $content, string $link, string $author, array $tags, array &$matched_rules = null, array &$matched_filters = null): array {
$scope = Tracer::start(__METHOD__);
$matches = array();
foreach ($filters as $filter) {
@ -1567,6 +1583,8 @@ class RSSUtils {
}
}
$scope->close();
return $matches;
}