X-Git-Url: https://git.mxchange.org/?a=blobdiff_plain;f=include%2Fpoller.php;h=08e71fd486b69c23b68b52ee3e560b715e25c2e8;hb=569cd459ec2e482ffff3de35877af8c7b3b02bfe;hp=0c5a4ff628c5ec3f53f016527eeb85c0db5d2b95;hpb=45d6f6c0a3ab8a0048dfb4fd3b28db065ad3a485;p=friendica.git diff --git a/include/poller.php b/include/poller.php index 0c5a4ff628..08e71fd486 100644 --- a/include/poller.php +++ b/include/poller.php @@ -1,4 +1,8 @@ set_baseurl(Config::get('system', 'url')); + + load_hooks(); + $a->start_process(); + if ($a->min_memory_reached()) { + return; + } + if (poller_max_connections_reached()) { return; } @@ -62,6 +73,11 @@ function poller_run($argv, $argc){ while ($r = poller_worker_process()) { + // Check free memory + if ($a->min_memory_reached()) { + return; + } + // Count active workers and compare them with a maximum value that depends on the load if (poller_too_much_workers()) { return; @@ -75,7 +91,6 @@ function poller_run($argv, $argc){ if (time() > ($starttime + 3600)) return; } - } /** @@ -91,8 +106,6 @@ function poller_execute($queue) { $mypid = getmypid(); - $cooldown = Config::get("system", "worker_cooldown", 0); - // Quit when in maintenance if (Config::get('system', 'maintenance', true)) { return false; @@ -138,8 +151,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]; @@ -155,83 +166,122 @@ function poller_execute($queue) { if (function_exists($funcname)) { - logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." ".$queue["parameter"]); - - $stamp = (float)microtime(true); - - 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(); - } + poller_exec_function($queue, $funcname, $argv); - // 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); + q("DELETE FROM `workerqueue` WHERE `id` = %d", intval($queue["id"])); + } else { + logger("Function ".$funcname." does not exist"); + } - $funcname($argv, $argc); + return true; +} - $a->process_id = $old_process_id; +/** + * @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) { - $duration = number_format(microtime(true) - $stamp, 3); + $a = get_app(); - logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - done in ".$duration." seconds."); + $mypid = getmypid(); - if (Config::get("system", "profiler")) { - $duration = microtime(true)-$a->performance["start"]; + $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); - logger("ID ".$queue["id"].": ".$funcname.": ".sprintf("DB: %s/%s, Net: %s, I/O: %s, Other: %s, Total: %s", - 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); + $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); + } - if (Config::get("rendertime", "callstack")) { - $o = "ID ".$queue["id"].": ".$funcname.": Database Read:\n"; + 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"; } - logger($o, LOGGER_DEBUG); } + } else { + $o = ''; } - if ($cooldown > 0) { - logger("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - in cooldown for ".$cooldown." seconds"); - sleep($cooldown); - } - - q("DELETE FROM `workerqueue` WHERE `id` = %d", intval($queue["id"])); - } else { - logger("Function ".$funcname." does not exist"); + 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); } - return true; + $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); + } } /** @@ -317,18 +367,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 @@ -351,14 +401,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); + } } + } } /** @@ -385,15 +438,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)) { @@ -428,7 +481,7 @@ function poller_too_much_workers() { // Are there fewer workers running as possible? Then fork a new one. 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); } @@ -513,21 +566,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; } @@ -535,7 +592,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; } @@ -547,7 +604,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; } @@ -574,7 +631,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; @@ -631,4 +688,3 @@ if (array_search(__file__,get_included_files())===0){ killme(); } -?>