X-Git-Url: https://git.mxchange.org/?a=blobdiff_plain;f=include%2Fpoller.php;h=5560b3340e6209fc4ab82c97ecd3619bc9840afc;hb=29306017198ade568f50718392b3df5a92bd04cc;hp=b631d2acd15637dad371c7cb122be456d45e22bf;hpb=4530f4ac9db4a3f9d53ef34ee7a185e2b31cc9be;p=friendica.git

diff --git a/include/poller.php b/include/poller.php
index b631d2acd1..5560b3340e 100644
--- a/include/poller.php
+++ b/include/poller.php
@@ -11,7 +11,6 @@ if (!file_exists("boot.php") AND (sizeof($_SERVER["argv"]) != 0)) {
 }
 
 use \Friendica\Core\Config;
-use \Friendica\Core\PConfig;
 
 require_once("boot.php");
 
@@ -29,9 +28,16 @@ function poller_run($argv, $argc){
 		unset($db_host, $db_user, $db_pass, $db_data);
 	};
 
+	Config::load();
+
 	// Quit when in maintenance
-	if (get_config('system', 'maintenance', true))
+	if (Config::get('system', 'maintenance', true)) {
 		return;
+	}
+
+	$a->set_baseurl(Config::get('system', 'url'));
+
+	load_hooks();
 
 	$a->start_process();
 
@@ -90,10 +96,8 @@ function poller_execute($queue) {
 
 	$mypid = getmypid();
 
-	$cooldown = Config::get("system", "worker_cooldown", 0);
-
 	// Quit when in maintenance
-	if (get_config('system', 'maintenance', true)) {
+	if (Config::get('system', 'maintenance', true)) {
 		return false;
 	}
 
@@ -137,8 +141,6 @@ function poller_execute($queue) {
 
 	$argv = json_decode($queue["parameter"]);
 
-	$argc = count($argv);
-
 	// Check for existance and validity of the include file
 	$include = $argv[0];
 
@@ -153,23 +155,8 @@ function poller_execute($queue) {
 	$funcname = str_replace(".php", "", basename($argv[0]))."_run";
 
 	if (function_exists($funcname)) {
-		logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." ".$queue["parameter"]);
-
-		// For better logging create a new process id for every worker call
-		// But preserve the old one for the worker
-		$old_process_id = $a->process_id;
-		$a->process_id = uniqid("wrk", true);
 
-		$funcname($argv, $argc);
-
-		$a->process_id = $old_process_id;
-
-		if ($cooldown > 0) {
-			logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - in cooldown for ".$cooldown." seconds");
-			sleep($cooldown);
-		}
-
-		logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - done");
+		poller_exec_function($queue, $funcname, $argv);
 
 		q("DELETE FROM `workerqueue` WHERE `id` = %d", intval($queue["id"]));
 	} else {
@@ -179,6 +166,114 @@ function poller_execute($queue) {
 	return true;
 }
 
+/**
+ * @brief Execute a function from the queue
+ *
+ * @param array $queue Workerqueue entry
+ * @param string $funcname name of the function
+ * @param array $argv Array of values to be passed to the function
+ */
+function poller_exec_function($queue, $funcname, $argv) {
+
+	$a = get_app();
+
+	$mypid = getmypid();
+
+	$argc = count($argv);
+
+	logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." ".$queue["parameter"]);
+
+	$stamp = (float)microtime(true);
+
+	// We use the callstack here to analyze the performance of executed worker entries.
+	// For this reason the variables have to be initialized.
+	if (Config::get("system", "profiler")) {
+		$a->performance["start"] = microtime(true);
+		$a->performance["database"] = 0;
+		$a->performance["database_write"] = 0;
+		$a->performance["network"] = 0;
+		$a->performance["file"] = 0;
+		$a->performance["rendering"] = 0;
+		$a->performance["parser"] = 0;
+		$a->performance["marktime"] = 0;
+		$a->performance["markstart"] = microtime(true);
+		$a->callstack = array();
+	}
+
+	// For better logging create a new process id for every worker call
+	// But preserve the old one for the worker
+	$old_process_id = $a->process_id;
+	$a->process_id = uniqid("wrk", true);
+
+	$funcname($argv, $argc);
+
+	$a->process_id = $old_process_id;
+
+	$duration = number_format(microtime(true) - $stamp, 3);
+
+	if ($duration > 3600) {
+		logger("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 1 hour (".round($duration/60, 3).")", LOGGER_DEBUG);
+	} elseif ($duration > 600) {
+		logger("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 10 minutes (".round($duration/60, 3).")", LOGGER_DEBUG);
+	} elseif ($duration > 300) {
+		logger("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 5 minutes (".round($duration/60, 3).")", LOGGER_DEBUG);
+	} elseif ($duration > 120) {
+		logger("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 2 minutes (".round($duration/60, 3).")", LOGGER_DEBUG);
+	}
+
+	logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - done in ".$duration." seconds.");
+
+	// Write down the performance values into the log
+	if (Config::get("system", "profiler")) {
+		$duration = microtime(true)-$a->performance["start"];
+
+		if (Config::get("rendertime", "callstack")) {
+			if (isset($a->callstack["database"])) {
+				$o = "\nDatabase Read:\n";
+				foreach ($a->callstack["database"] AS $func => $time) {
+					$time = round($time, 3);
+					if ($time > 0)
+						$o .= $func.": ".$time."\n";
+				}
+			}
+			if (isset($a->callstack["database_write"])) {
+				$o .= "\nDatabase Write:\n";
+				foreach ($a->callstack["database_write"] AS $func => $time) {
+					$time = round($time, 3);
+					if ($time > 0)
+						$o .= $func.": ".$time."\n";
+				}
+			}
+			if (isset($a->callstack["network"])) {
+				$o .= "\nNetwork:\n";
+				foreach ($a->callstack["network"] AS $func => $time) {
+					$time = round($time, 3);
+					if ($time > 0)
+						$o .= $func.": ".$time."\n";
+				}
+			}
+		} else {
+			$o = '';
+		}
+
+		logger("ID ".$queue["id"].": ".$funcname.": ".sprintf("DB: %s/%s, Net: %s, I/O: %s, Other: %s, Total: %s".$o,
+			number_format($a->performance["database"] - $a->performance["database_write"], 2),
+			number_format($a->performance["database_write"], 2),
+			number_format($a->performance["network"], 2),
+			number_format($a->performance["file"], 2),
+			number_format($duration - ($a->performance["database"] + $a->performance["network"] + $a->performance["file"]), 2),
+			number_format($duration, 2)),
+			LOGGER_DEBUG);
+	}
+
+	$cooldown = Config::get("system", "worker_cooldown", 0);
+
+	if ($cooldown > 0) {
+		logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - in cooldown for ".$cooldown." seconds");
+		sleep($cooldown);
+	}
+}
+
 /**
  * @brief Checks if the number of database connections has reached a critical limit.
  *
@@ -187,7 +282,7 @@ function poller_execute($queue) {
 function poller_max_connections_reached() {
 
 	// Fetch the max value from the config. This is needed when the system cannot detect the correct value by itself.
-	$max = get_config("system", "max_connections");
+	$max = Config::get("system", "max_connections");
 
 	// Fetch the percentage level where the poller will get active
 	$maxlevel = Config::get("system", "max_connections_level", 75);
@@ -262,18 +357,18 @@ function poller_max_connections_reached() {
  *
  */
 function poller_kill_stale_workers() {
-	$r = q("SELECT `pid`, `executed`, `priority`, `parameter` FROM `workerqueue` WHERE `executed` != '0000-00-00 00:00:00'");
+	$r = q("SELECT `pid`, `executed`, `priority`, `parameter` FROM `workerqueue` WHERE `executed` > '%s'", dbesc(NULL_DATE));
 
 	if (!dbm::is_result($r)) {
 		// No processing here needed
 		return;
 	}
 
-	foreach($r AS $pid)
-		if (!posix_kill($pid["pid"], 0))
-			q("UPDATE `workerqueue` SET `executed` = '0000-00-00 00:00:00', `pid` = 0 WHERE `pid` = %d",
-				intval($pid["pid"]));
-		else {
+	foreach ($r AS $pid) {
+		if (!posix_kill($pid["pid"], 0)) {
+			q("UPDATE `workerqueue` SET `executed` = '%s', `pid` = 0 WHERE `pid` = %d",
+				dbesc(NULL_DATE), intval($pid["pid"]));
+		} else {
 			// Kill long running processes
 
 			// Check if the priority is in a valid range
@@ -296,14 +391,17 @@ function poller_kill_stale_workers() {
 				// We killed the stale process.
 				// To avoid a blocking situation we reschedule the process at the beginning of the queue.
 				// Additionally we are lowering the priority.
-				q("UPDATE `workerqueue` SET `executed` = '0000-00-00 00:00:00', `created` = '%s',
+				q("UPDATE `workerqueue` SET `executed` = '%s', `created` = '%s',
 							`priority` = %d, `pid` = 0 WHERE `pid` = %d",
+					dbesc(NULL_DATE),
 					dbesc(datetime_convert()),
 					intval(PRIORITY_NEGLIGIBLE),
 					intval($pid["pid"]));
-			} else
+			} else {
 				logger("Worker process ".$pid["pid"]." (".implode(" ", $argv).") now runs for ".round($duration)." of ".$max_duration." allowed minutes. That's okay.", LOGGER_DEBUG);
+			}
 		}
+	}
 }
 
 /**
@@ -330,15 +428,15 @@ function poller_too_much_workers() {
 		$slope = $maxworkers / pow($maxsysload, $exponent);
 		$queues = ceil($slope * pow(max(0, $maxsysload - $load), $exponent));
 
-		$s = q("SELECT COUNT(*) AS `total` FROM `workerqueue` WHERE `executed` = '0000-00-00 00:00:00'");
+		$s = q("SELECT COUNT(*) AS `total` FROM `workerqueue` WHERE `executed` <= '%s'", dbesc(NULL_DATE));
 		$entries = $s[0]["total"];
 
 		if (Config::get("system", "worker_fastlane", false) AND ($queues > 0) AND ($entries > 0) AND ($active >= $queues)) {
-			$s = q("SELECT `priority` FROM `workerqueue` WHERE `executed` = '0000-00-00 00:00:00' ORDER BY `priority` LIMIT 1");
+			$s = q("SELECT `priority` FROM `workerqueue` WHERE `executed` <= '%s' ORDER BY `priority` LIMIT 1", dbesc(NULL_DATE));
 			$top_priority = $s[0]["priority"];
 
-			$s = q("SELECT `id` FROM `workerqueue` WHERE `priority` <= %d AND `executed` != '0000-00-00 00:00:00' LIMIT 1",
-				intval($top_priority));
+			$s = q("SELECT `id` FROM `workerqueue` WHERE `priority` <= %d AND `executed` > '%s' LIMIT 1",
+				intval($top_priority), dbesc(NULL_DATE));
 			$high_running = dbm::is_result($s);
 
 			if (!$high_running AND ($top_priority > PRIORITY_UNDEFINED) AND ($top_priority < PRIORITY_NEGLIGIBLE)) {
@@ -371,9 +469,9 @@ function poller_too_much_workers() {
 		logger("Load: ".$load."/".$maxsysload." - processes: ".$active."/".$entries." (".$processlist.") - maximum: ".$queues."/".$maxqueues, LOGGER_DEBUG);
 
 		// Are there fewer workers running as possible? Then fork a new one.
-		if (!get_config("system", "worker_dont_fork") AND ($queues > ($active + 1)) AND ($entries > 1)) {
+		if (!Config::get("system", "worker_dont_fork") AND ($queues > ($active + 1)) AND ($entries > 1)) {
 			logger("Active workers: ".$active."/".$queues." Fork a new worker.", LOGGER_DEBUG);
-			$args = array("php", "include/poller.php", "no_cron");
+			$args = array("include/poller.php", "no_cron");
 			$a = get_app();
 			$a->proc_run($args);
 		}
@@ -458,21 +556,25 @@ function poller_worker_process() {
 	if (poller_passing_slow($highest_priority)) {
 		// Are there waiting processes with a higher priority than the currently highest?
 		$r = q("SELECT * FROM `workerqueue`
-				WHERE `executed` = '0000-00-00 00:00:00' AND `priority` < %d
-				ORDER BY `priority`, `created` LIMIT 1", dbesc($highest_priority));
-		if (dbm::is_result($r))
+				WHERE `executed` <= '%s' AND `priority` < %d
+				ORDER BY `priority`, `created` LIMIT 1",
+				dbesc(NULL_DATE),
+				intval($highest_priority));
+		if (dbm::is_result($r)) {
 			return $r;
-
+		}
 		// Give slower processes some processing time
 		$r = q("SELECT * FROM `workerqueue`
-				WHERE `executed` = '0000-00-00 00:00:00' AND `priority` > %d
-				ORDER BY `priority`, `created` LIMIT 1", dbesc($highest_priority));
+				WHERE `executed` <= '%s' AND `priority` > %d
+				ORDER BY `priority`, `created` LIMIT 1",
+				dbesc(NULL_DATE),
+				intval($highest_priority));
 	}
 
 	// If there is no result (or we shouldn't pass lower processes) we check without priority limit
-	if (($highest_priority == 0) OR !dbm::is_result($r))
-		$r = q("SELECT * FROM `workerqueue` WHERE `executed` = '0000-00-00 00:00:00' ORDER BY `priority`, `created` LIMIT 1");
-
+	if (($highest_priority == 0) OR !dbm::is_result($r)) {
+		$r = q("SELECT * FROM `workerqueue` WHERE `executed` <= '%s' ORDER BY `priority`, `created` LIMIT 1", dbesc(NULL_DATE));
+	}
 	return $r;
 }
 
@@ -480,7 +582,7 @@ function poller_worker_process() {
  * @brief Call the front end worker
  */
 function call_worker() {
-	if (!Config::get("system", "frontend_worker") OR !Config::get("system", "worker")) {
+	if (!Config::get("system", "frontend_worker")) {
 		return;
 	}
 
@@ -492,7 +594,7 @@ function call_worker() {
  * @brief Call the front end worker if there aren't any active
  */
 function call_worker_if_idle() {
-	if (!Config::get("system", "frontend_worker") OR !Config::get("system", "worker")) {
+	if (!Config::get("system", "frontend_worker")) {
 		return;
 	}
 
@@ -500,7 +602,7 @@ function call_worker_if_idle() {
 	if (function_exists("proc_open")) {
 		// When was the last time that we called the worker?
 		// Less than one minute? Then we quit
-		if ((time() - get_config("system", "worker_started")) < 60) {
+		if ((time() - Config::get("system", "worker_started")) < 60) {
 			return;
 		}
 
@@ -519,7 +621,7 @@ function call_worker_if_idle() {
 
 		logger('Call poller', LOGGER_DEBUG);
 
-		$args = array("php", "include/poller.php", "no_cron");
+		$args = array("include/poller.php", "no_cron");
 		$a = get_app();
 		$a->proc_run($args);
 		return;