* logger: add optional HTML output

* feed debugger: add checkbox to dump feed XML

classes/debug.php

@@ -5,6 +5,8 @@ class Debug {
 	const LOG_VERBOSE = 1;
 	const LOG_EXTENDED = 2;
 
+	const SEPARATOR = "<-{log-separator}->";
+
 	const ALL_LOG_LEVELS = [
 		Debug::LOG_DISABLED,
 		Debug::LOG_NORMAL,
@@ -35,6 +37,7 @@ class Debug {
 	private static bool $enabled = false;
 	private static bool $quiet = false;
 	private static ?string $logfile = null;
+	private static bool $enable_html = false;
 
 	private static int $loglevel = self::LOG_NORMAL;
 
@@ -82,58 +85,77 @@ class Debug {
 		}
 	}
 
+	public static function enable_html(bool $enable) : void {
+		self::$enable_html = $enable;
+	}
+
 	/**
 	 * @param Debug::LOG_* $level log level
 	 */
     public static function log(string $message, int $level = Debug::LOG_NORMAL): bool {
 
-        if (!self::$enabled || self::$loglevel < $level) return false;
+		if (!self::$enabled || self::$loglevel < $level) return false;
 
-        $ts = date("H:i:s", time());
+		$ts = date("H:i:s", time());
-        if (function_exists('posix_getpid')) {
+		if (function_exists('posix_getpid')) {
-            $ts = "$ts/" . posix_getpid();
+			$ts = "$ts/" . posix_getpid();
-        }
+		}
 
-        if (self::$logfile) {
+		$orig_message = $message;
-            $fp = fopen(self::$logfile, 'a+');
 
-            if ($fp) {
+		if ($message === self::SEPARATOR) {
-                $locked = false;
+			$message = self::$enable_html ? "<hr/>" :
+				"=================================================================================================================================";
+		}
 
-                if (function_exists("flock")) {
+		if (self::$logfile) {
-                    $tries = 0;
+			$fp = fopen(self::$logfile, 'a+');
 
-                    // try to lock logfile for writing
+			if ($fp) {
-                    while ($tries < 5 && !$locked = flock($fp, LOCK_EX | LOCK_NB)) {
+					$locked = false;
-                        sleep(1);
-                        ++$tries;
-                    }
 
-                    if (!$locked) {
+					if (function_exists("flock")) {
-                        fclose($fp);
+						$tries = 0;
-                        user_error("Unable to lock debugging log file: " . self::$logfile, E_USER_WARNING);
-                        return false;
-                    }
-                }
 
-                fputs($fp, "[$ts] $message\n");
+						// try to lock logfile for writing
+						while ($tries < 5 && !$locked = flock($fp, LOCK_EX | LOCK_NB)) {
+							sleep(1);
+							++$tries;
+						}
 
-                if (function_exists("flock")) {
+						if (!$locked) {
-                    flock($fp, LOCK_UN);
+							fclose($fp);
-                }
+							user_error("Unable to lock debugging log file: " . self::$logfile, E_USER_WARNING);
+							return false;
+						}
+					}
 
-                fclose($fp);
+					fputs($fp, "[$ts] $message\n");
 
-                if (self::$quiet)
+					if (function_exists("flock")) {
-                    return false;
+						flock($fp, LOCK_UN);
+					}
 
-            } else {
+					fclose($fp);
-                user_error("Unable to open debugging log file: " . self::$logfile, E_USER_WARNING);
-            }
-        }
 
-        print "[$ts] $message\n";
+					if (self::$quiet)
+						return false;
+
+			} else {
+					user_error("Unable to open debugging log file: " . self::$logfile, E_USER_WARNING);
+			}
+		}
+
+		if (self::$enable_html) {
+			if ($orig_message === self::SEPARATOR) {
+				print "$message\n";
+			} else {
+				print "<span class='log-timestamp'>$ts</span> <span class='log-message'>$message</span>\n";
+			}
+		} else {
+			print "[$ts] $message\n";
+		}
 
 		return true;
-    }
+	}
 }

classes/feeds.php

@@ -708,6 +708,23 @@ class Feeds extends Handler_Protected {
 				body.css_loading * {
 					display : none;
 				}
+
+				.feed-xml {
+					color : green;
+				}
+
+				.log-timestamp {
+					color : gray;
+				}
+
+				.log-timestamp::before {
+					content: "["
+				}
+
+				.log-timestamp::after {
+					content: "]"
+				}
+
 			</style>
 			<script>
 				dojoConfig = {
@@ -759,6 +776,10 @@ class Feeds extends Handler_Protected {
 							<label class="checkbox"><?= \Controls\checkbox_tag("force_rehash", isset($_REQUEST["force_rehash"])) ?> Force rehash</label>
 						</fieldset>
 
+						<fieldset class="narrow">
+							<label class="checkbox"><?= \Controls\checkbox_tag("dump_feed_xml", isset($_REQUEST["dump_feed_xml"])) ?> Dump feed XML</label>
+						</fieldset>
+
 						<?= \Controls\submit_tag("Continue") ?>
 					</form>
 
@@ -767,7 +788,7 @@ class Feeds extends Handler_Protected {
 					<pre><?php
 
 					if ($do_update) {
-						RSSUtils::update_rss_feed($feed_id, true);
+						RSSUtils::update_rss_feed($feed_id, true, true);
 					}
 
 					?></pre>

classes/rssutils.php

@@ -1,5 +1,6 @@
 <?php
 class RSSUtils {
+
 	/**
 	 * @param array<string, mixed> $article
 	 */
@@ -351,9 +352,10 @@ class RSSUtils {
 		}
 	}
 
-	static function update_rss_feed(int $feed, bool $no_cache = false) : bool {
+	static function update_rss_feed(int $feed, bool $no_cache = false, bool $html_output = false) : bool {
 
 		$scope = Tracer::start(__METHOD__, [], func_get_args());
+		Debug::enable_html($html_output);
 		Debug::log("start", Debug::LOG_VERBOSE);
 
 		$pdo = Db::pdo();
@@ -424,6 +426,7 @@ class RSSUtils {
 		$rss_hash = false;
 
 		$force_refetch = isset($_REQUEST["force_refetch"]);
+		$dump_feed_xml = isset($_REQUEST["dump_feed_xml"]);
 		$feed_data = "";
 
 		Debug::log("running HOOK_FETCH_FEED handlers...", Debug::LOG_VERBOSE);
@@ -569,6 +572,14 @@ class RSSUtils {
 		$pff_owner_uid = $feed_obj->owner_uid;
 		$pff_feed_url = $feed_obj->feed_url;
 
+		if ($dump_feed_xml) {
+			Debug::log("feed data before hooks:", Debug::LOG_VERBOSE);
+
+			Debug::log(Debug::SEPARATOR, Debug::LOG_VERBOSE);
+			print("<code class='feed-xml'>" . htmlspecialchars($feed_data). "</code>\n");
+			Debug::log(Debug::SEPARATOR, Debug::LOG_VERBOSE);
+		}
+
 		$start_ts = microtime(true);
 		$pluginhost->chain_hooks_callback(PluginHost::HOOK_FEED_FETCHED,
 			function ($result, $plugin) use (&$feed_data, $start_ts) {
@@ -583,6 +594,14 @@ class RSSUtils {
 			Debug::log("feed data has not been modified by a plugin.", Debug::LOG_VERBOSE);
 		}
 
+		if ($dump_feed_xml) {
+			Debug::log("feed data after hooks:", Debug::LOG_VERBOSE);
+
+			Debug::log(Debug::SEPARATOR, Debug::LOG_VERBOSE);
+			print("<code class='feed-xml'>" . htmlspecialchars($feed_data). "</code>\n");
+			Debug::log(Debug::SEPARATOR, Debug::LOG_VERBOSE);
+		}
+
 		$rss = new FeedParser($feed_data);
 		$rss->init();
 
@@ -697,8 +716,7 @@ class RSSUtils {
 
 				$pdo->beginTransaction();
 
-				Debug::log("=================================================================================================================================",
+				Debug::log(Debug::SEPARATOR, Debug::LOG_VERBOSE);
-					Debug::LOG_VERBOSE);
 
 				if (Debug::get_loglevel() >= 3) {
 					print_r($item);
@@ -1290,8 +1308,7 @@ class RSSUtils {
 				$a_scope->close();
 			}
 
-			Debug::log("=================================================================================================================================",
+			Debug::log(Debug::SEPARATOR, Debug::LOG_VERBOSE);
-					Debug::LOG_VERBOSE);
 
 			Debug::log("purging feed...", Debug::LOG_VERBOSE);