From: Michael Date: Wed, 27 Feb 2019 06:41:14 +0000 (+0000) Subject: Merge remote-tracking branch 'upstream/2019.03-RC' into worker2 X-Git-Url: https://git.mxchange.org/?a=commitdiff_plain;h=fb371e10486f535ffcb52569a55e185b5a78c015;p=friendica.git Merge remote-tracking branch 'upstream/2019.03-RC' into worker2 --- fb371e10486f535ffcb52569a55e185b5a78c015 diff --cc src/Core/Worker.php index 9691514d04,7b661d863f..b0b9fc2cf2 --- a/src/Core/Worker.php +++ b/src/Core/Worker.php @@@ -416,16 -394,15 +399,16 @@@ class Worke * The execution time is the productive time. * By changing parameters like the maximum number of workers we can check the effectivness. */ - $dbtotal = number_format(self::$db_duration - (self::$db_duration_count + self::$db_duration_write + self::$db_duration_stat), 4); - $dbcount = number_format(self::$db_duration_count, 4); - $dbstat = number_format(self::$db_duration_stat, 4); - $dbwrite = number_format(self::$db_duration_write, 4); - $dblock = number_format(self::$lock_duration, 4); - $rest = number_format(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 4); - $exec = number_format($duration, 4); + $dbtotal = round(self::$db_duration, 2); + $dbread = round(self::$db_duration - (self::$db_duration_count + self::$db_duration_write + self::$db_duration_stat), 2); + $dbcount = round(self::$db_duration_count, 2); + $dbstat = round(self::$db_duration_stat, 2); + $dbwrite = round(self::$db_duration_write, 2); + $dblock = round(self::$lock_duration, 2); + $rest = round(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 2); + $exec = round($duration, 2); - Logger::info('Performance:', ['mode' => self::$mode, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'lock' => $dblock, 'total' => $dbtotal, 'rest' => $rest, 'exec' => $exec]); - $logger->info('Performance log.', ['total' => $dbtotal, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'block' => $dblock, 'rest' => $rest, 'exec' => $exec]); ++ $logger->info('Performance log.', ['mode' => self::$mode, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'lock' => $dblock, 'total' => $dbtotal, 'rest' => $rest, 'exec' => $exec]); self::$up_start = microtime(true); self::$db_duration = 0; @@@ -433,90 -410,20 +416,21 @@@ self::$db_duration_stat = 0; self::$db_duration_write = 0; self::$lock_duration = 0; + self::$mode = 2; if ($duration > 3600) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 1 hour (".round($duration/60, 3).")", Logger::DEBUG); + $logger->info('Longer than 1 hour.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } elseif ($duration > 600) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 10 minutes (".round($duration/60, 3).")", Logger::DEBUG); + $logger->info('Longer than 10 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } elseif ($duration > 300) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 5 minutes (".round($duration/60, 3).")", Logger::DEBUG); + $logger->info('Longer than 5 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } elseif ($duration > 120) { - Logger::log("Prio ".$queue["priority"].": ".$queue["parameter"]." - longer than 2 minutes (".round($duration/60, 3).")", Logger::DEBUG); + $logger->info('Longer than 2 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => round($duration/60, 3)]); } - Logger::log("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - done in ".number_format($duration, 4)." seconds. Process PID: ".$new_process_id); + $workerLogger->info('Process done. ', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' => number_format($duration, 4)]); - // Write down the performance values into the log - if (Config::get("system", "profiler")) { - $duration = microtime(true)-$a->performance["start"]; - - $o = ''; - 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["dache"])) { - $o .= "\nCache Read:\n"; - foreach ($a->callstack["dache"] as $func => $time) { - $time = round($time, 3); - if ($time > 0) { - $o .= $func.": ".$time."\n"; - } - } - } - if (isset($a->callstack["dache_write"])) { - $o .= "\nCache Write:\n"; - foreach ($a->callstack["dache_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::log( - "ID ".$queue["id"].": ".$funcname.": ".sprintf( - "DB: %s/%s, Cache: %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["cache"], 2), - number_format($a->performance["cache_write"], 2), - number_format($a->performance["network"], 2), - number_format($a->performance["file"], 2), - number_format($duration - ($a->performance["database"] - + $a->performance["cache"] + $a->performance["cache_write"] - + $a->performance["network"] + $a->performance["file"]), 2), - number_format($duration, 2) - ), - Logger::DEBUG - ); - } + $a->getProfiler()->saveLog($a->getLogger(), "ID " . $queue["id"] . ": " . $funcname); $cooldown = Config::get("system", "worker_cooldown", 0);