viewfeed: reintroduce timestamps, fix debugging, fix some indents

classes/feeds.php

@@ -7,6 +7,9 @@ class Feeds extends Handler_Protected {
 
 	 private $params;
 
+	 private $viewfeed_timestamp;
+	 private $viewfeed_timestamp_last;
+
     function csrf_ignore($method) {
 		$csrf_ignored = array("index");
 
@@ -122,6 +125,8 @@ class Feeds extends Handler_Protected {
 
 		$disable_cache = false;
 
+		$this->mark_timestamp("init");
+
 		$reply = array();
 
 		$rgba_cache = array();
@@ -203,6 +208,8 @@ class Feeds extends Handler_Protected {
 			$qfh_ret = $this->queryFeedHeadlines($params);
 		}
 
+		$this->mark_timestamp("db query");
+
 		$vfeed_group_enabled = get_pref("VFEED_GROUP_BY_FEED") &&
 			!(in_array($feed, self::NEVER_GROUP_FEEDS) && !$cat_view);
 
@@ -233,10 +240,13 @@ class Feeds extends Handler_Protected {
 
 		$reply['content'] = [];
 
+		$this->mark_timestamp("object header");
+
 		$headlines_count = 0;
 
         if (is_object($result)) {
 			while ($line = $result->fetch(PDO::FETCH_ASSOC)) {
+				$this->mark_timestamp("article start: " . $line["id"] . " " . $line["title"]);
 
 				++$headlines_count;
 
@@ -250,6 +260,8 @@ class Feeds extends Handler_Protected {
 					}
 				}
 
+				$this->mark_timestamp("   hook_query_headlines");
+
 				$id = $line["id"];
 
 				// frontend doesn't expect pdo returning booleans as strings on mysql
@@ -293,6 +305,8 @@ class Feeds extends Handler_Protected {
 					array_push($topmost_article_ids, $id);
 				}
 
+				$this->mark_timestamp("   labels");
+
 				if (!$line["feed_title"]) $line["feed_title"] = "";
 
 				$line["buttons_left"] = "";
@@ -305,20 +319,32 @@ class Feeds extends Handler_Protected {
 					$line["buttons"] .= $p->hook_article_button($line);
 				}
 
+				$this->mark_timestamp("   pre-sanitize");
+
 				$line["content"] = Sanitizer::sanitize($line["content"],
 					$line['hide_images'], false, $line["site_url"], $highlight_words, $line["id"]);
 
+				$this->mark_timestamp("   sanitize");
+
 				foreach (PluginHost::getInstance()->get_hooks(PluginHost::HOOK_RENDER_ARTICLE_CDM) as $p) {
 					$line = $p->hook_render_article_cdm($line);
+
+					$this->mark_timestamp("       hook_render_cdm: " . get_class($p));
 				}
 
+				$this->mark_timestamp("   hook_render_cdm");
+
 				$line['content'] = DiskCache::rewriteUrls($line['content']);
 
+				$this->mark_timestamp("   disk_cache_rewrite");
+
 				if ($line['note'])
 					$line['note'] = Article::format_article_note($id, $line['note']);
 				else
 					$line['note'] = "";
 
+				$this->mark_timestamp("   note");
+
 				if (!get_pref("CDM_EXPANDED")) {
 					$line["cdm_excerpt"] = "<span class='collapse'>
 						<i class='material-icons' onclick='return Article.cdmUnsetActive(event)'
@@ -329,9 +355,13 @@ class Feeds extends Handler_Protected {
 					}
 				}
 
+				$this->mark_timestamp("   pre-enclosures");
+
 				$line["enclosures"] = Article::format_article_enclosures($id, $line["always_display_enclosures"],
 					$line["content"], $line["hide_images"]);
 
+				$this->mark_timestamp("   enclosures");
+
 				if ($line["orig_feed_id"]) {
 
 					$ofgh = $this->pdo->prepare("SELECT * FROM ttrss_archived_feeds
@@ -343,13 +373,16 @@ class Feeds extends Handler_Protected {
 					}
 				}
 
+				$this->mark_timestamp("   orig-feed-id");
+
 				$line["updated_long"] = TimeHelper::make_local_datetime($line["updated"],true);
 				$line["updated"] = TimeHelper::make_local_datetime($line["updated"], false, false, 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
@@ -357,6 +390,8 @@ class Feeds extends Handler_Protected {
 
 				$line["tags_str"] = Article::format_tags_string($tags, $id);
 
+				$this->mark_timestamp("   tags");
+
 				if (self::feedHasIcon($feed_id)) {
 					$line['feed_icon'] = "<img class=\"icon\" src=\"".ICONS_URL."/$feed_id.ico\" alt=\"\">";
 				} else {
@@ -366,6 +401,8 @@ class Feeds extends Handler_Protected {
 			    //setting feed headline background color, needs to change text color based on dark/light
 				$fav_color = $line['favicon_avg_color'];
 
+				$this->mark_timestamp("   pre-color");
+
 				require_once "colors.php";
 
 				if (!isset($rgba_cache[$feed_id])) {
@@ -380,6 +417,8 @@ class Feeds extends Handler_Protected {
 				    $line['feed_bg_color'] = 'rgba(' . implode(",", $rgba_cache[$feed_id]) . ',0.3)';
 				}
 
+				$this->mark_timestamp("   color");
+
 				/* we don't need those */
 
 				foreach (["date_entered", "guid", "last_published", "last_marked", "tag_cache", "favicon_avg_color",
@@ -387,9 +426,13 @@ class Feeds extends Handler_Protected {
 					unset($line[$k]);
 
 				array_push($reply['content'], $line);
+
+				$this->mark_timestamp("article end");
 			}
 		}
 
+		$this->mark_timestamp("end of articles");
+
 		if (!$headlines_count) {
 
 			if (is_object($result)) {
@@ -450,6 +493,8 @@ class Feeds extends Handler_Protected {
 			}
 		}
 
+		$this->mark_timestamp("end");
+
 		return array($topmost_article_ids, $headlines_count, $feed, $disable_cache, $reply);
 	}
 
@@ -1856,7 +1901,7 @@ class Feeds extends Handler_Protected {
 							$query_strategy_part ORDER BY $order_by
 							$limit_query_part $offset_query_part";
 
-			if ($_REQUEST["debug"]) print $query;
+			//if ($_REQUEST["debug"]) print $query;
 
 			$res = $pdo->query($query);
 		}
@@ -2317,5 +2362,25 @@ class Feeds extends Handler_Protected {
 
 		return [$query, $skip_first_id];
 	}
+
+	function mark_timestamp($label) {
+
+		if (!$_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;
+	}
+
 }
 

js/App.js

@@ -1037,7 +1037,8 @@ const App = {
                //window.open("backend.php?op=feeds&method=update_debugger&feed_id=" + Feeds.getActive());
 
                /* global __csrf_token */
-               App.postOpenWindow("backend.php", {op: "feeds", method: "update_debugger", feed_id: Feeds.getActive(), csrf_token: __csrf_token});
+               App.postOpenWindow("backend.php", {op: "feeds", method: "update_debugger",
+                  feed_id: Feeds.getActive(), csrf_token: __csrf_token});
 
             } else {
                alert("You can't debug this kind of feed.");
@@ -1045,7 +1046,10 @@ const App = {
          };
 
          this.hotkey_actions["feed_debug_viewfeed"] = () => {
-            Feeds.open({feed: Feeds.getActive(), is_cat: Feeds.activeIsCat(), viewfeed_debug: true});
+            //Feeds.open({feed: Feeds.getActive(), is_cat: Feeds.activeIsCat(), viewfeed_debug: true});
+
+            App.postOpenWindow("backend.php", {op: "feeds", method: "view",
+               feed: Feeds.getActive(), timestamps: 1, is_cat: Feeds.activeIsCat(), csrf_token: __csrf_token});
          };
 
          this.hotkey_actions["feed_edit"] = () => {