more tracing

This commit is contained in:
Andrew Dolgov 2023-04-09 22:15:16 +03:00
parent d68c736e47
commit e18295a364
No known key found for this signature in database
GPG Key ID: 1A56B4FA25D4AF2A
8 changed files with 92 additions and 31 deletions

View File

@ -298,6 +298,8 @@ class Article extends Handler_Protected {
* @return array{'formatted': string, 'entries': array<int, array<string, mixed>>}
*/
static function _format_enclosures(int $id, bool $always_display_enclosures, string $article_content, bool $hide_images = false): array {
$scope = Tracer::start(__METHOD__);
$enclosures = self::_get_enclosures($id);
$enclosures_formatted = "";
@ -324,6 +326,7 @@ class Article extends Handler_Protected {
$enclosures_formatted, $enclosures, $id, $always_display_enclosures, $article_content, $hide_images);
if (!empty($enclosures_formatted)) {
$scope->close();
return [
'formatted' => $enclosures_formatted,
'entries' => []
@ -367,6 +370,7 @@ class Article extends Handler_Protected {
}
}
$scope->close();
return $rv;
}
@ -374,6 +378,7 @@ class Article extends Handler_Protected {
* @return array<int, string>
*/
static function _get_tags(int $id, int $owner_uid = 0, ?string $tag_cache = null): array {
$scope = Tracer::start(__METHOD__);
$a_id = $id;
@ -422,6 +427,7 @@ class Article extends Handler_Protected {
$sth->execute([$tags_str, $id, $owner_uid]);
}
$scope->close();
return $tags;
}
@ -516,6 +522,8 @@ class Article extends Handler_Protected {
* @return array<int, array<int, int|string>>
*/
static function _get_labels(int $id, ?int $owner_uid = null): array {
$scope = Tracer::start(__METHOD__, []);
$rv = array();
if (!$owner_uid) $owner_uid = $_SESSION["uid"];
@ -561,6 +569,8 @@ class Article extends Handler_Protected {
else
Labels::update_cache($owner_uid, $id, array("no-labels" => 1));
$scope->close();
return $rv;
}

View File

@ -145,7 +145,7 @@ class Counters {
* @return array<int, array<string, int|string>>
*/
private static function get_feeds(array $feed_ids = null): array {
$scope = Tracer::start(__FUNCTION__);
$scope = Tracer::start(__METHOD__);
$ret = [];
@ -221,7 +221,7 @@ class Counters {
* @return array<int, array<string, int|string>>
*/
private static function get_global(): array {
$scope = Tracer::start(__FUNCTION__);
$scope = Tracer::start(__METHOD__);
$ret = [
[
@ -248,7 +248,7 @@ class Counters {
* @return array<int, array<string, int|string>>
*/
private static function get_virt(): array {
$scope = Tracer::start(__FUNCTION__);
$scope = Tracer::start(__METHOD__);
$ret = [];
@ -304,7 +304,7 @@ class Counters {
* @return array<int, array<string, int|string>>
*/
static function get_labels(array $label_ids = null): array {
$scope = Tracer::start(__FUNCTION__);
$scope = Tracer::start(__METHOD__);
$ret = [];

View File

@ -221,7 +221,11 @@ class DiskCache implements Cache_Adapter {
}
public function remove(string $filename): bool {
return $this->adapter->remove($filename);
$scope = Tracer::start(__METHOD__);
$rc = $this->adapter->remove($filename);
$scope->close();
return $rc;
}
public function set_dir(string $dir) : void {
@ -244,7 +248,11 @@ class DiskCache implements Cache_Adapter {
}
public function exists(string $filename): bool {
return $this->adapter->exists(basename($filename));
$scope = Tracer::start(__METHOD__);
$rc = $this->adapter->exists(basename($filename));
$scope->close();
return $rc;
}
/**
@ -260,7 +268,11 @@ class DiskCache implements Cache_Adapter {
* @return int|false Bytes written or false if an error occurred.
*/
public function put(string $filename, $data) {
return $this->adapter->put(basename($filename), $data);
$scope = Tracer::start(__METHOD__);
$rc = $this->adapter->put(basename($filename), $data);
$scope->close();
return $rc;
}
/** @deprecated we can't assume cached files are local, and other storages
@ -304,7 +316,7 @@ class DiskCache implements Cache_Adapter {
}
public function send(string $filename) {
$scope = Tracer::start(__FUNCTION__, ['filename' => $filename]);
$scope = Tracer::start(__METHOD__, ['filename' => $filename]);
$filename = basename($filename);
@ -401,8 +413,14 @@ class DiskCache implements Cache_Adapter {
// plugins work on original source URLs used before caching
// NOTE: URLs should be already absolutized because this is called after sanitize()
static public function rewrite_urls(string $str): string {
$scope = Tracer::start(__METHOD__);
$res = trim($str);
if (!$res) return '';
if (!$res) {
$scope->close();
return '';
}
$doc = new DOMDocument();
if (@$doc->loadHTML('<?xml encoding="UTF-8">' . $res)) {
@ -414,6 +432,8 @@ class DiskCache implements Cache_Adapter {
$need_saving = false;
foreach ($entries as $entry) {
$e_scope = Tracer::start('entry', ['tagName' => $entry->tagName]);
foreach (array('src', 'poster') as $attr) {
if ($entry->hasAttribute($attr)) {
$url = $entry->getAttribute($attr);
@ -445,6 +465,8 @@ class DiskCache implements Cache_Adapter {
$entry->setAttribute("srcset", RSSUtils::encode_srcset($matches));
}
$e_scope->close();
}
if ($need_saving) {
@ -454,6 +476,9 @@ class DiskCache implements Cache_Adapter {
$res = $doc->saveHTML();
}
}
$scope->close();
return $res;
}
}

View File

@ -71,7 +71,7 @@ class Feeds extends Handler_Protected {
$disable_cache = false;
$this->_mark_timestamp("init");
$scope = Tracer::start(__METHOD__, [], func_get_args());
$reply = [];
$rgba_cache = [];
@ -157,8 +157,6 @@ class Feeds extends Handler_Protected {
$qfh_ret = $this->_get_headlines($params);
}
$this->_mark_timestamp("db query");
$vfeed_group_enabled = get_pref(Prefs::VFEED_GROUP_BY_FEED) &&
!(in_array($feed, self::NEVER_GROUP_FEEDS) && !$cat_view);
@ -176,6 +174,8 @@ class Feeds extends Handler_Protected {
$reply['search_query'] = [$search, $search_language];
$reply['vfeed_group_enabled'] = $vfeed_group_enabled;
$p_scope = Tracer::start('plugin_menu_items');
$plugin_menu_items = "";
PluginHost::getInstance()->chain_hooks_callback(PluginHost::HOOK_HEADLINE_TOOLBAR_SELECT_MENU_ITEM2,
function ($result) use (&$plugin_menu_items) {
@ -208,13 +208,15 @@ class Feeds extends Handler_Protected {
},
$feed, $cat_view, $qfh_ret);
$this->_mark_timestamp("object header");
$p_scope->close();
$a_scope = Tracer::start('articles');
$headlines_count = 0;
if ($result instanceof PDOStatement) {
while ($line = $result->fetch(PDO::FETCH_ASSOC)) {
$this->_mark_timestamp("article start: " . $line["id"] . " " . $line["title"]);
$aa_scope = Tracer::start('article', ['id' => $line['id']]);
++$headlines_count;
@ -232,8 +234,6 @@ class Feeds extends Handler_Protected {
$line, $max_excerpt_length);
}
$this->_mark_timestamp(" hook_query_headlines");
$id = $line["id"];
// frontend doesn't expect pdo returning booleans as strings on mysql
@ -312,6 +312,7 @@ class Feeds extends Handler_Protected {
$line);
$line["buttons"] = "";
PluginHost::getInstance()->chain_hooks_callback(PluginHost::HOOK_ARTICLE_BUTTON,
function ($result, $plugin) use (&$line, &$button_doc) {
if ($result && $button_doc->loadXML($result)) {
@ -335,13 +336,9 @@ class Feeds extends Handler_Protected {
},
$line);
$this->_mark_timestamp(" pre-sanitize");
$line["content"] = Sanitizer::sanitize($line["content"],
$line['hide_images'], null, $line["site_url"], $highlight_words, $line["id"]);
$this->_mark_timestamp(" sanitize");
if (!get_pref(Prefs::CDM_EXPANDED)) {
$line["cdm_excerpt"] = "<span class='collapse'>
<i class='material-icons' onclick='return Article.cdmUnsetActive(event)'
@ -352,8 +349,6 @@ class Feeds extends Handler_Protected {
}
}
$this->_mark_timestamp(" pre-enclosures");
if ($line["num_enclosures"] > 0) {
$line["enclosures"] = Article::_format_enclosures($id,
sql_bool_to_bool($line["always_display_enclosures"]),
@ -429,10 +424,12 @@ class Feeds extends Handler_Protected {
array_push($reply['content'], $line);
$this->_mark_timestamp("article end");
$aa_scope->close();
}
}
$a_scope->close();
$this->_mark_timestamp("end of articles");
if (!$headlines_count) {
@ -494,7 +491,7 @@ class Feeds extends Handler_Protected {
}
}
$this->_mark_timestamp("end");
$scope->close();
return array($topmost_article_ids, $headlines_count, $feed, $disable_cache, $reply);
}
@ -987,7 +984,7 @@ class Feeds extends Handler_Protected {
* @throws PDOException
*/
static function _get_counters($feed, bool $is_cat = false, bool $unread_only = false, ?int $owner_uid = null): int {
$scope = Tracer::start(__FUNCTION__, [], func_get_args());
$scope = Tracer::start(__METHOD__, [], func_get_args());
$n_feed = (int) $feed;
$need_entries = false;
@ -1497,6 +1494,8 @@ class Feeds extends Handler_Protected {
*/
static function _get_headlines($params): array {
$scope = Tracer::start(__METHOD__, [], func_get_args());
$pdo = Db::pdo();
// WARNING: due to highly dynamic nature of this query its going to quote parameters
@ -1989,8 +1988,9 @@ class Feeds extends Handler_Protected {
$res = $pdo->query($query);
}
return array($res, $feed_title, $feed_site_url, $last_error, $last_updated, $search_words, $first_id, $vfeed_query_part != "", $query_error_override);
$scope->close();
return array($res, $feed_title, $feed_site_url, $last_error, $last_updated, $search_words, $first_id, $vfeed_query_part != "", $query_error_override);
}
/**

View File

@ -339,6 +339,7 @@ class PluginHost {
*/
function chain_hooks_callback(string $hook, Closure $callback, &...$args): void {
$method = strtolower((string)$hook);
$scope = Tracer::start(__METHOD__, ['hook' => $hook]);
foreach ($this->get_hooks((string)$hook) as $plugin) {
//Debug::log("invoking: " . get_class($plugin) . "->$hook()", Debug::$LOG_VERBOSE);
@ -352,6 +353,8 @@ class PluginHost {
user_error($err, E_USER_WARNING);
}
}
$scope->close();
}
/**
@ -431,6 +434,8 @@ class PluginHost {
* @param PluginHost::KIND_* $kind
*/
function load(string $classlist, int $kind, int $owner_uid = null, bool $skip_init = false): void {
$scope = Tracer::start(__METHOD__);
$plugins = explode(",", $classlist);
$this->owner_uid = (int) $owner_uid;
@ -439,18 +444,21 @@ class PluginHost {
$class = trim($class);
$class_file = strtolower(basename(clean($class)));
$p_scope = Tracer::start('load_plugin', ['file' => $class_file]);
// try system plugin directory first
$file = dirname(__DIR__) . "/plugins/$class_file/init.php";
if (!file_exists($file)) {
$file = dirname(__DIR__) . "/plugins.local/$class_file/init.php";
if (!file_exists($file))
if (!file_exists($file)) {
$p_scope->close();
continue;
}
}
if (!isset($this->plugins[$class])) {
// WIP hack
// we can't catch incompatible method signatures via Throwable
// this also enables global tt-rss safe mode in case there are more plugins like this
@ -464,6 +472,8 @@ class PluginHost {
$_SESSION["safe_mode"] = 1;
$p_scope->getSpan()->setTag('error', 'plugin is blacklisted');
$p_scope->close();
continue;
}
@ -474,16 +484,21 @@ class PluginHost {
} catch (Error $err) {
user_error($err, E_USER_WARNING);
$p_scope->getSpan()->setTag('error', $err);
$p_scope->close();
continue;
}
if (class_exists($class) && is_subclass_of($class, "Plugin")) {
$plugin = new $class($this);
$plugin_api = $plugin->api_version();
if ($plugin_api < self::API_VERSION) {
user_error("Plugin $class is not compatible with current API version (need: " . self::API_VERSION . ", got: $plugin_api)", E_USER_WARNING);
$p_scope->getSpan()->setTag('error', 'plugin is not compatible with API version');
$p_scope->close();
continue;
}
@ -516,11 +531,15 @@ class PluginHost {
} catch (Error $err) {
user_error($err, E_USER_WARNING);
}
}
}
$p_scope->close();
}
$this->load_data();
$scope->close();
}
function is_system(Plugin $plugin): bool {
@ -613,6 +632,8 @@ class PluginHost {
}
private function load_data(): void {
$scope = Tracer::start(__METHOD__);
if ($this->owner_uid && !$this->data_loaded && get_schema_version() > 100) {
$sth = $this->pdo->prepare("SELECT name, content FROM ttrss_plugin_storage
WHERE owner_uid = ?");
@ -624,6 +645,8 @@ class PluginHost {
$this->data_loaded = true;
}
$scope->close();
}
private function save_data(string $plugin): void {

View File

@ -1104,7 +1104,7 @@ class Pref_Feeds extends Handler_Protected {
* @return array<string, mixed>
*/
private function feedlist_init_feed(int $feed_id, ?string $title = null, bool $unread = false, string $error = '', string $updated = ''): array {
$scope = Tracer::start(__FUNCTION__, [], func_get_args());
$scope = Tracer::start(__METHOD__, []);
if (!$title)
$title = Feeds::_get_title($feed_id, false);

View File

@ -106,7 +106,7 @@ class RPC extends Handler_Protected {
}
function getAllCounters(): void {
$scope = Tracer::start(__FUNCTION__);
$scope = Tracer::start(__METHOD__);
@$seq = (int) $_REQUEST['seq'];

View File

@ -63,6 +63,7 @@ class Sanitizer {
* @return false|string The HTML, or false if an error occurred.
*/
public static function sanitize(string $str, ?bool $force_remove_images = false, int $owner = null, string $site_url = null, array $highlight_words = null, int $article_id = null) {
$scope = Tracer::start(__METHOD__);
if (!$owner && isset($_SESSION["uid"]))
$owner = $_SESSION["uid"];
@ -223,6 +224,8 @@ class Sanitizer {
$res = $doc->saveHTML();
$scope->close();
/* strip everything outside of <body>...</body> */
$res_frag = array();