]> git.mxchange.org Git - friendica.git/blob - src/Core/Worker.php
0a97c11c13724d25db490fab2b78cbb63a89bab2
[friendica.git] / src / Core / Worker.php
1 <?php
2 /**
3  * @file src/Core/Worker.php
4  */
5 namespace Friendica\Core;
6
7 use Friendica\BaseObject;
8 use Friendica\Database\DBA;
9 use Friendica\Model\Process;
10 use Friendica\Util\DateTimeFormat;
11 use Friendica\Util\Logger\WorkerLogger;
12 use Friendica\Util\Network;
13
14 /**
15  * @file src/Core/Worker.php
16  *
17  * @brief Contains the class for the worker background job processing
18  */
19
20 /**
21  * @brief Worker methods
22  */
23 class Worker
24 {
25         private static $up_start;
26         private static $db_duration = 0;
27         private static $db_duration_count = 0;
28         private static $db_duration_write = 0;
29         private static $db_duration_stat = 0;
30         private static $lock_duration = 0;
31         private static $last_update;
32
33         /**
34          * @brief Processes the tasks that are in the workerqueue table
35          *
36          * @param boolean $run_cron Should the cron processes be executed?
37          * @return void
38          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
39          */
40         public static function processQueue($run_cron = true)
41         {
42                 $a = \get_app();
43
44                 // Ensure that all "strtotime" operations do run timezone independent
45                 date_default_timezone_set('UTC');
46
47                 self::$up_start = microtime(true);
48
49                 // At first check the maximum load. We shouldn't continue with a high load
50                 if ($a->isMaxLoadReached()) {
51                         Logger::log('Pre check: maximum load reached, quitting.', Logger::DEBUG);
52                         return;
53                 }
54
55                 // We now start the process. This is done after the load check since this could increase the load.
56                 self::startProcess();
57
58                 // Kill stale processes every 5 minutes
59                 $last_cleanup = Config::get('system', 'worker_last_cleaned', 0);
60                 if (time() > ($last_cleanup + 300)) {
61                         Config::set('system', 'worker_last_cleaned', time());
62                         self::killStaleWorkers();
63                 }
64
65                 // Count active workers and compare them with a maximum value that depends on the load
66                 if (self::tooMuchWorkers()) {
67                         Logger::log('Pre check: Active worker limit reached, quitting.', Logger::DEBUG);
68                         return;
69                 }
70
71                 // Do we have too few memory?
72                 if ($a->isMinMemoryReached()) {
73                         Logger::log('Pre check: Memory limit reached, quitting.', Logger::DEBUG);
74                         return;
75                 }
76
77                 // Possibly there are too much database connections
78                 if (self::maxConnectionsReached()) {
79                         Logger::log('Pre check: maximum connections reached, quitting.', Logger::DEBUG);
80                         return;
81                 }
82
83                 // Possibly there are too much database processes that block the system
84                 if ($a->isMaxProcessesReached()) {
85                         Logger::log('Pre check: maximum processes reached, quitting.', Logger::DEBUG);
86                         return;
87                 }
88
89                 // Now we start additional cron processes if we should do so
90                 if ($run_cron) {
91                         self::runCron();
92                 }
93
94                 $starttime = time();
95
96                 // We fetch the next queue entry that is about to be executed
97                 while ($r = self::workerProcess()) {
98                         foreach ($r as $entry) {
99                                 // Assure that the priority is an integer value
100                                 $entry['priority'] = (int)$entry['priority'];
101
102                                 // The work will be done
103                                 if (!self::execute($entry)) {
104                                         Logger::log('Process execution failed, quitting.', Logger::DEBUG);
105                                         return;
106                                 }
107
108                                 // If possible we will fetch new jobs for this worker
109                                 if (!self::getWaitingJobForPID() && Lock::acquire('worker_process', 0)) {
110                                         self::findWorkerProcesses();
111                                         Lock::release('worker_process');
112                                 }
113                         }
114
115                         // To avoid the quitting of multiple workers only one worker at a time will execute the check
116                         if (Lock::acquire('worker', 0)) {
117                                 // Count active workers and compare them with a maximum value that depends on the load
118                                 if (self::tooMuchWorkers()) {
119                                         Logger::log('Active worker limit reached, quitting.', Logger::DEBUG);
120                                         Lock::release('worker');
121                                         return;
122                                 }
123
124                                 // Check free memory
125                                 if ($a->isMinMemoryReached()) {
126                                         Logger::log('Memory limit reached, quitting.', Logger::DEBUG);
127                                         Lock::release('worker');
128                                         return;
129                                 }
130                                 Lock::release('worker');
131                         }
132
133                         // Quit the worker once every 5 minutes
134                         if (time() > ($starttime + 300)) {
135                                 Logger::log('Process lifetime reached, quitting.', Logger::DEBUG);
136                                 return;
137                         }
138                 }
139
140                 // Cleaning up. Possibly not needed, but it doesn't harm anything.
141                 if (Config::get('system', 'worker_daemon_mode', false)) {
142                         self::IPCSetJobState(false);
143                 }
144                 Logger::log("Couldn't select a workerqueue entry, quitting process " . getmypid() . ".", Logger::DEBUG);
145         }
146
147         /**
148          * @brief Check if non executed tasks do exist in the worker queue
149          *
150          * @return boolean Returns "true" if tasks are existing
151          * @throws \Exception
152          */
153         private static function entriesExists()
154         {
155                 $stamp = (float)microtime(true);
156                 $exists = DBA::exists('workerqueue', ["NOT `done` AND `pid` = 0 AND `next_try` < ?", DateTimeFormat::utcNow()]);
157                 self::$db_duration += (microtime(true) - $stamp);
158                 return $exists;
159         }
160
161         /**
162          * @brief Returns the number of deferred entries in the worker queue
163          *
164          * @return integer Number of deferred entries in the worker queue
165          * @throws \Exception
166          */
167         private static function deferredEntries()
168         {
169                 $stamp = (float)microtime(true);
170                 $count = DBA::count('workerqueue', ["NOT `done` AND `pid` = 0 AND `next_try` > ?", DateTimeFormat::utcNow()]);
171                 self::$db_duration += (microtime(true) - $stamp);
172                 self::$db_duration_count += (microtime(true) - $stamp);
173                 return $count;
174         }
175
176         /**
177          * @brief Returns the number of non executed entries in the worker queue
178          *
179          * @return integer Number of non executed entries in the worker queue
180          * @throws \Exception
181          */
182         private static function totalEntries()
183         {
184                 $stamp = (float)microtime(true);
185                 $count = DBA::count('workerqueue', ['done' => false, 'pid' => 0]);
186                 self::$db_duration += (microtime(true) - $stamp);
187                 self::$db_duration_count += (microtime(true) - $stamp);
188                 return $count;
189         }
190
191         /**
192          * @brief Returns the highest priority in the worker queue that isn't executed
193          *
194          * @return integer Number of active worker processes
195          * @throws \Exception
196          */
197         private static function highestPriority()
198         {
199                 $stamp = (float)microtime(true);
200                 $condition = ["`pid` = 0 AND NOT `done` AND `next_try` < ?", DateTimeFormat::utcNow()];
201                 $workerqueue = DBA::selectFirst('workerqueue', ['priority'], $condition, ['order' => ['priority']]);
202                 self::$db_duration += (microtime(true) - $stamp);
203                 if (DBA::isResult($workerqueue)) {
204                         return $workerqueue["priority"];
205                 } else {
206                         return 0;
207                 }
208         }
209
210         /**
211          * @brief Returns if a process with the given priority is running
212          *
213          * @param integer $priority The priority that should be checked
214          *
215          * @return integer Is there a process running with that priority?
216          * @throws \Exception
217          */
218         private static function processWithPriorityActive($priority)
219         {
220                 $condition = ["`priority` <= ? AND `pid` != 0 AND NOT `done`", $priority];
221                 return DBA::exists('workerqueue', $condition);
222         }
223
224         /**
225          * @brief Execute a worker entry
226          *
227          * @param array $queue Workerqueue entry
228          *
229          * @return boolean "true" if further processing should be stopped
230          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
231          */
232         public static function execute($queue)
233         {
234                 $a = \get_app();
235
236                 $mypid = getmypid();
237
238                 // Quit when in maintenance
239                 if (Config::get('system', 'maintenance', false, true)) {
240                         Logger::log("Maintenance mode - quit process ".$mypid, Logger::DEBUG);
241                         return false;
242                 }
243
244                 // Constantly check the number of parallel database processes
245                 if ($a->isMaxProcessesReached()) {
246                         Logger::log("Max processes reached for process ".$mypid, Logger::DEBUG);
247                         return false;
248                 }
249
250                 // Constantly check the number of available database connections to let the frontend be accessible at any time
251                 if (self::maxConnectionsReached()) {
252                         Logger::log("Max connection reached for process ".$mypid, Logger::DEBUG);
253                         return false;
254                 }
255
256                 $argv = json_decode($queue["parameter"], true);
257
258                 // Check for existance and validity of the include file
259                 $include = $argv[0];
260
261                 if (method_exists(sprintf('Friendica\Worker\%s', $include), 'execute')) {
262                         // We constantly update the "executed" date every minute to avoid being killed too soon
263                         if (!isset(self::$last_update)) {
264                                 self::$last_update = strtotime($queue["executed"]);
265                         }
266
267                         $age = (time() - self::$last_update) / 60;
268                         self::$last_update = time();
269
270                         if ($age > 1) {
271                                 $stamp = (float)microtime(true);
272                                 DBA::update('workerqueue', ['executed' => DateTimeFormat::utcNow()], ['pid' => $mypid, 'done' => false]);
273                                 self::$db_duration += (microtime(true) - $stamp);
274                                 self::$db_duration_write += (microtime(true) - $stamp);
275                         }
276
277                         array_shift($argv);
278
279                         self::execFunction($queue, $include, $argv, true);
280
281                         $stamp = (float)microtime(true);
282                         $condition = ["`id` = ? AND `next_try` < ?", $queue['id'], DateTimeFormat::utcNow()];
283                         if (DBA::update('workerqueue', ['done' => true], $condition)) {
284                                 Config::set('system', 'last_worker_execution', DateTimeFormat::utcNow());
285                         }
286                         self::$db_duration = (microtime(true) - $stamp);
287                         self::$db_duration_write += (microtime(true) - $stamp);
288
289                         return true;
290                 }
291
292                 // The script could be provided as full path or only with the function name
293                 if ($include == basename($include)) {
294                         $include = "include/".$include.".php";
295                 }
296
297                 if (!validate_include($include)) {
298                         Logger::log("Include file ".$argv[0]." is not valid!");
299                         $stamp = (float)microtime(true);
300                         DBA::delete('workerqueue', ['id' => $queue["id"]]);
301                         self::$db_duration = (microtime(true) - $stamp);
302                         self::$db_duration_write += (microtime(true) - $stamp);
303                         return true;
304                 }
305
306                 require_once $include;
307
308                 $funcname = str_replace(".php", "", basename($argv[0]))."_run";
309
310                 if (function_exists($funcname)) {
311                         // We constantly update the "executed" date every minute to avoid being killed too soon
312                         if (!isset(self::$last_update)) {
313                                 self::$last_update = strtotime($queue["executed"]);
314                         }
315
316                         $age = (time() - self::$last_update) / 60;
317                         self::$last_update = time();
318
319                         if ($age > 1) {
320                                 $stamp = (float)microtime(true);
321                                 DBA::update('workerqueue', ['executed' => DateTimeFormat::utcNow()], ['pid' => $mypid, 'done' => false]);
322                                 self::$db_duration += (microtime(true) - $stamp);
323                                 self::$db_duration_write += (microtime(true) - $stamp);
324                         }
325
326                         self::execFunction($queue, $funcname, $argv, false);
327
328                         $stamp = (float)microtime(true);
329                         if (DBA::update('workerqueue', ['done' => true], ['id' => $queue["id"]])) {
330                                 Config::set('system', 'last_worker_execution', DateTimeFormat::utcNow());
331                         }
332                         self::$db_duration = (microtime(true) - $stamp);
333                         self::$db_duration_write += (microtime(true) - $stamp);
334                 } else {
335                         Logger::log("Function ".$funcname." does not exist");
336                         $stamp = (float)microtime(true);
337                         DBA::delete('workerqueue', ['id' => $queue["id"]]);
338                         self::$db_duration = (microtime(true) - $stamp);
339                         self::$db_duration_write += (microtime(true) - $stamp);
340                 }
341
342                 return true;
343         }
344
345         /**
346          * @brief Execute a function from the queue
347          *
348          * @param array   $queue       Workerqueue entry
349          * @param string  $funcname    name of the function
350          * @param array   $argv        Array of values to be passed to the function
351          * @param boolean $method_call boolean
352          * @return void
353          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
354          */
355         private static function execFunction($queue, $funcname, $argv, $method_call)
356         {
357                 $a = \get_app();
358
359                 $argc = count($argv);
360
361                 $logger = $a->getLogger();
362                 $workerLogger = new WorkerLogger($logger, $funcname);
363
364                 $workerLogger ->info("Process start.", ['priority' => $queue["priority"], 'id' => $queue["id"]]);
365
366                 $stamp = (float)microtime(true);
367
368                 // We use the callstack here to analyze the performance of executed worker entries.
369                 // For this reason the variables have to be initialized.
370                 $a->getProfiler()->reset();
371
372                 $a->queue = $queue;
373
374                 $up_duration = microtime(true) - self::$up_start;
375
376                 // Reset global data to avoid interferences
377                 unset($_SESSION);
378
379                 // Set the workerLogger as new default logger
380                 Logger::init($workerLogger);
381                 if ($method_call) {
382                         call_user_func_array(sprintf('Friendica\Worker\%s::execute', $funcname), $argv);
383                 } else {
384                         $funcname($argv, $argc);
385                 }
386                 Logger::init($logger);
387
388                 unset($a->queue);
389
390                 $duration = (microtime(true) - $stamp);
391
392                 /* With these values we can analyze how effective the worker is.
393                  * The database and rest time should be low since this is the unproductive time.
394                  * The execution time is the productive time.
395                  * By changing parameters like the maximum number of workers we can check the effectivness.
396                 */
397                 $dbtotal = number_format(self::$db_duration - (self::$db_duration_count + self::$db_duration_write + self::$db_duration_stat), 4);
398                 $dbcount = number_format(self::$db_duration_count, 4);
399                 $dbstat  = number_format(self::$db_duration_stat, 4);
400                 $dbwrite = number_format(self::$db_duration_write, 4);
401                 $dblock  = number_format(self::$lock_duration, 4);
402                 $rest    = number_format(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 4);
403                 $exec    = number_format($duration, 4);
404
405                 $logger->info('Performance log.', ['total' => $dbtotal, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'block' => $dblock, 'rest' => $rest, 'exec' => $exec]);
406
407                 self::$up_start = microtime(true);
408                 self::$db_duration = 0;
409                 self::$db_duration_count = 0;
410                 self::$db_duration_stat = 0;
411                 self::$db_duration_write = 0;
412                 self::$lock_duration = 0;
413
414                 if ($duration > 3600) {
415                         $logger->info('Longer than 1 hour.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' =>   round($duration/60, 3)]);
416                 } elseif ($duration > 600) {
417                         $logger->info('Longer than 10 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' =>   round($duration/60, 3)]);
418                 } elseif ($duration > 300) {
419                         $logger->info('Longer than 5 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' =>   round($duration/60, 3)]);
420                 } elseif ($duration > 120) {
421                         $logger->info('Longer than 2 minutes.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' =>   round($duration/60, 3)]);
422                 }
423
424                 $workerLogger->info('Process done. ', ['priority' => $queue["priority"], 'id' => $queue["id"], 'duration' =>   number_format($duration, 4)]);
425
426                 $a->getProfiler()->saveLog($a->getLogger(), "ID " . $queue["id"] . ": " . $funcname);
427
428                 $cooldown = Config::get("system", "worker_cooldown", 0);
429
430                 if ($cooldown > 0) {
431                         $logger->info('Cooldown.', ['priority' => $queue["priority"], 'id' => $queue["id"], 'cooldown' => $cooldown]);
432                         sleep($cooldown);
433                 }
434         }
435
436         /**
437          * @brief Checks if the number of database connections has reached a critical limit.
438          *
439          * @return bool Are more than 3/4 of the maximum connections used?
440          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
441          */
442         private static function maxConnectionsReached()
443         {
444                 // Fetch the max value from the config. This is needed when the system cannot detect the correct value by itself.
445                 $max = Config::get("system", "max_connections");
446
447                 // Fetch the percentage level where the worker will get active
448                 $maxlevel = Config::get("system", "max_connections_level", 75);
449
450                 if ($max == 0) {
451                         // the maximum number of possible user connections can be a system variable
452                         $r = DBA::fetchFirst("SHOW VARIABLES WHERE `variable_name` = 'max_user_connections'");
453                         if (DBA::isResult($r)) {
454                                 $max = $r["Value"];
455                         }
456                         // Or it can be granted. This overrides the system variable
457                         $stamp = (float)microtime(true);
458                         $r = DBA::p('SHOW GRANTS');
459                         self::$db_duration += (microtime(true) - $stamp);
460                         while ($grants = DBA::fetch($r)) {
461                                 $grant = array_pop($grants);
462                                 if (stristr($grant, "GRANT USAGE ON")) {
463                                         if (preg_match("/WITH MAX_USER_CONNECTIONS (\d*)/", $grant, $match)) {
464                                                 $max = $match[1];
465                                         }
466                                 }
467                         }
468                         DBA::close($r);
469                 }
470
471                 // If $max is set we will use the processlist to determine the current number of connections
472                 // The processlist only shows entries of the current user
473                 if ($max != 0) {
474                         $stamp = (float)microtime(true);
475                         $r = DBA::p('SHOW PROCESSLIST');
476                         self::$db_duration += (microtime(true) - $stamp);
477                         $used = DBA::numRows($r);
478                         DBA::close($r);
479
480                         Logger::log("Connection usage (user values): ".$used."/".$max, Logger::DEBUG);
481
482                         $level = ($used / $max) * 100;
483
484                         if ($level >= $maxlevel) {
485                                 Logger::log("Maximum level (".$maxlevel."%) of user connections reached: ".$used."/".$max);
486                                 return true;
487                         }
488                 }
489
490                 // We will now check for the system values.
491                 // This limit could be reached although the user limits are fine.
492                 $r = DBA::fetchFirst("SHOW VARIABLES WHERE `variable_name` = 'max_connections'");
493                 if (!DBA::isResult($r)) {
494                         return false;
495                 }
496                 $max = intval($r["Value"]);
497                 if ($max == 0) {
498                         return false;
499                 }
500                 $r = DBA::fetchFirst("SHOW STATUS WHERE `variable_name` = 'Threads_connected'");
501                 if (!DBA::isResult($r)) {
502                         return false;
503                 }
504                 $used = intval($r["Value"]);
505                 if ($used == 0) {
506                         return false;
507                 }
508                 Logger::log("Connection usage (system values): ".$used."/".$max, Logger::DEBUG);
509
510                 $level = $used / $max * 100;
511
512                 if ($level < $maxlevel) {
513                         return false;
514                 }
515                 Logger::log("Maximum level (".$level."%) of system connections reached: ".$used."/".$max);
516                 return true;
517         }
518
519         /**
520          * @brief fix the queue entry if the worker process died
521          * @return void
522          * @throws \Exception
523          */
524         private static function killStaleWorkers()
525         {
526                 $stamp = (float)microtime(true);
527                 $entries = DBA::select(
528                         'workerqueue',
529                         ['id', 'pid', 'executed', 'priority', 'parameter'],
530                         ['NOT `done` AND `pid` != 0'],
531                         ['order' => ['priority', 'created']]
532                 );
533                 self::$db_duration += (microtime(true) - $stamp);
534
535                 while ($entry = DBA::fetch($entries)) {
536                         if (!posix_kill($entry["pid"], 0)) {
537                                 $stamp = (float)microtime(true);
538                                 DBA::update(
539                                         'workerqueue',
540                                         ['executed' => DBA::NULL_DATETIME, 'pid' => 0],
541                                         ['id' => $entry["id"]]
542                                 );
543                                 self::$db_duration += (microtime(true) - $stamp);
544                                 self::$db_duration_write += (microtime(true) - $stamp);
545                         } else {
546                                 // Kill long running processes
547                                 // Check if the priority is in a valid range
548                                 if (!in_array($entry["priority"], [PRIORITY_CRITICAL, PRIORITY_HIGH, PRIORITY_MEDIUM, PRIORITY_LOW, PRIORITY_NEGLIGIBLE])) {
549                                         $entry["priority"] = PRIORITY_MEDIUM;
550                                 }
551
552                                 // Define the maximum durations
553                                 $max_duration_defaults = [PRIORITY_CRITICAL => 720, PRIORITY_HIGH => 10, PRIORITY_MEDIUM => 60, PRIORITY_LOW => 180, PRIORITY_NEGLIGIBLE => 720];
554                                 $max_duration = $max_duration_defaults[$entry["priority"]];
555
556                                 $argv = json_decode($entry["parameter"], true);
557                                 $argv[0] = basename($argv[0]);
558
559                                 // How long is the process already running?
560                                 $duration = (time() - strtotime($entry["executed"])) / 60;
561                                 if ($duration > $max_duration) {
562                                         Logger::log("Worker process ".$entry["pid"]." (".substr(json_encode($argv), 0, 50).") took more than ".$max_duration." minutes. It will be killed now.");
563                                         posix_kill($entry["pid"], SIGTERM);
564
565                                         // We killed the stale process.
566                                         // To avoid a blocking situation we reschedule the process at the beginning of the queue.
567                                         // Additionally we are lowering the priority. (But not PRIORITY_CRITICAL)
568                                         $new_priority = $entry["priority"];
569                                         if ($entry["priority"] == PRIORITY_HIGH) {
570                                                 $new_priority = PRIORITY_MEDIUM;
571                                         } elseif ($entry["priority"] == PRIORITY_MEDIUM) {
572                                                 $new_priority = PRIORITY_LOW;
573                                         } elseif ($entry["priority"] != PRIORITY_CRITICAL) {
574                                                 $new_priority = PRIORITY_NEGLIGIBLE;
575                                         }
576                                         $stamp = (float)microtime(true);
577                                         DBA::update(
578                                                 'workerqueue',
579                                                 ['executed' => DBA::NULL_DATETIME, 'created' => DateTimeFormat::utcNow(), 'priority' => $new_priority, 'pid' => 0],
580                                                 ['id' => $entry["id"]]
581                                         );
582                                         self::$db_duration += (microtime(true) - $stamp);
583                                         self::$db_duration_write += (microtime(true) - $stamp);
584                                 } else {
585                                         Logger::log("Worker process ".$entry["pid"]." (".substr(json_encode($argv), 0, 50).") now runs for ".round($duration)." of ".$max_duration." allowed minutes. That's okay.", Logger::DEBUG);
586                                 }
587                         }
588                 }
589         }
590
591         /**
592          * @brief Checks if the number of active workers exceeds the given limits
593          *
594          * @return bool Are there too much workers running?
595          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
596          */
597         private static function tooMuchWorkers()
598         {
599                 $queues = Config::get("system", "worker_queues", 4);
600
601                 $maxqueues = $queues;
602
603                 $active = self::activeWorkers();
604
605                 // Decrease the number of workers at higher load
606                 $load = System::currentLoad();
607                 if ($load) {
608                         $maxsysload = intval(Config::get("system", "maxloadavg", 50));
609
610                         /* Default exponent 3 causes queues to rapidly decrease as load increases.
611                          * If you have 20 max queues at idle, then you get only 5 queues at 37.1% of $maxsysload.
612                          * For some environments, this rapid decrease is not needed.
613                          * With exponent 1, you could have 20 max queues at idle and 13 at 37% of $maxsysload.
614                          */
615                         $exponent = intval(Config::get('system', 'worker_load_exponent', 3));
616                         $slope = pow(max(0, $maxsysload - $load) / $maxsysload, $exponent);
617                         $queues = intval(ceil($slope * $maxqueues));
618
619                         $processlist = '';
620
621                         if (Config::get('system', 'worker_jpm')) {
622                                 $intervals = explode(',', Config::get('system', 'worker_jpm_range'));
623                                 $jobs_per_minute = [];
624                                 foreach ($intervals as $interval) {
625                                         if ($interval == 0) {
626                                                 continue;
627                                         } else {
628                                                 $interval = (int)$interval;
629                                         }
630
631                                         $stamp = (float)microtime(true);
632                                         $jobs = DBA::p("SELECT COUNT(*) AS `jobs` FROM `workerqueue` WHERE `done` AND `executed` > UTC_TIMESTAMP() - INTERVAL ? MINUTE", $interval);
633                                         self::$db_duration += (microtime(true) - $stamp);
634                                         self::$db_duration_stat += (microtime(true) - $stamp);
635                                         if ($job = DBA::fetch($jobs)) {
636                                                 $jobs_per_minute[$interval] = number_format($job['jobs'] / $interval, 0);
637                                         }
638                                         DBA::close($jobs);
639                                 }
640                                 $processlist = ' - jpm: '.implode('/', $jobs_per_minute);
641                         }
642
643                         // Create a list of queue entries grouped by their priority
644                         $listitem = [0 => ''];
645
646                         $idle_workers = $active;
647
648                         $deferred = self::deferredEntries();
649
650                         if (Config::get('system', 'worker_debug')) {
651                                 $waiting_processes = 0;
652                                 // Now adding all processes with workerqueue entries
653                                 $stamp = (float)microtime(true);
654                                 $jobs = DBA::p("SELECT COUNT(*) AS `entries`, `priority` FROM `workerqueue` WHERE NOT `done` AND `next_try` < ? GROUP BY `priority`", DateTimeFormat::utcNow());
655                                 self::$db_duration += (microtime(true) - $stamp);
656                                 self::$db_duration_stat += (microtime(true) - $stamp);
657                                 while ($entry = DBA::fetch($jobs)) {
658                                         $stamp = (float)microtime(true);
659                                         $processes = DBA::p("SELECT COUNT(*) AS `running` FROM `process` INNER JOIN `workerqueue` ON `workerqueue`.`pid` = `process`.`pid` WHERE NOT `done` AND `priority` = ?", $entry["priority"]);
660                                         self::$db_duration += (microtime(true) - $stamp);
661                                         self::$db_duration_stat += (microtime(true) - $stamp);
662                                         if ($process = DBA::fetch($processes)) {
663                                                 $idle_workers -= $process["running"];
664                                                 $waiting_processes += $entry["entries"];
665                                                 $listitem[$entry["priority"]] = $entry["priority"].":".$process["running"]."/".$entry["entries"];
666                                         }
667                                         DBA::close($processes);
668                                 }
669                                 DBA::close($jobs);
670                                 $entries = $deferred + $waiting_processes;
671                         } else {
672                                 $entries = self::totalEntries();
673                                 $waiting_processes = max(0, $entries - $deferred);
674                                 $stamp = (float)microtime(true);
675                                 $jobs = DBA::p("SELECT COUNT(*) AS `running`, `priority` FROM `process` INNER JOIN `workerqueue` ON `workerqueue`.`pid` = `process`.`pid` AND NOT `done` GROUP BY `priority` ORDER BY `priority`");
676                                 self::$db_duration += (microtime(true) - $stamp);
677                                 self::$db_duration_stat += (microtime(true) - $stamp);
678
679                                 while ($entry = DBA::fetch($jobs)) {
680                                         $idle_workers -= $entry["running"];
681                                         $listitem[$entry["priority"]] = $entry["priority"].":".$entry["running"];
682                                 }
683                                 DBA::close($jobs);
684                         }
685
686                         $listitem[0] = "0:" . max(0, $idle_workers);
687
688                         $processlist .= ' ('.implode(', ', $listitem).')';
689
690                         if (Config::get("system", "worker_fastlane", false) && ($queues > 0) && self::entriesExists() && ($active >= $queues)) {
691                                 $top_priority = self::highestPriority();
692                                 $high_running = self::processWithPriorityActive($top_priority);
693
694                                 if (!$high_running && ($top_priority > PRIORITY_UNDEFINED) && ($top_priority < PRIORITY_NEGLIGIBLE)) {
695                                         Logger::log("There are jobs with priority ".$top_priority." waiting but none is executed. Open a fastlane.", Logger::DEBUG);
696                                         $queues = $active + 1;
697                                 }
698                         }
699
700                         Logger::log("Load: " . $load ."/" . $maxsysload . " - processes: " . $deferred . "/" . $active . "/" . $waiting_processes . $processlist . " - maximum: " . $queues . "/" . $maxqueues, Logger::DEBUG);
701
702                         // Are there fewer workers running as possible? Then fork a new one.
703                         if (!Config::get("system", "worker_dont_fork", false) && ($queues > ($active + 1)) && ($entries > 1)) {
704                                 Logger::log("Active workers: ".$active."/".$queues." Fork a new worker.", Logger::DEBUG);
705                                 if (Config::get('system', 'worker_daemon_mode', false)) {
706                                         self::IPCSetJobState(true);
707                                 } else {
708                                         self::spawnWorker();
709                                 }
710                         }
711                 }
712
713                 // if there are too much worker, we don't spawn a new one.
714                 if (Config::get('system', 'worker_daemon_mode', false) && ($active > $queues)) {
715                         self::IPCSetJobState(false);
716                 }
717
718                 return $active > $queues;
719         }
720
721         /**
722          * @brief Returns the number of active worker processes
723          *
724          * @return integer Number of active worker processes
725          * @throws \Exception
726          */
727         private static function activeWorkers()
728         {
729                 $stamp = (float)microtime(true);
730                 $count = DBA::count('process', ['command' => 'Worker.php']);
731                 self::$db_duration += (microtime(true) - $stamp);
732                 return $count;
733         }
734
735         /**
736          * @brief Returns waiting jobs for the current process id
737          *
738          * @return array waiting workerqueue jobs
739          * @throws \Exception
740          */
741         private static function getWaitingJobForPID()
742         {
743                 $stamp = (float)microtime(true);
744                 $r = DBA::select('workerqueue', [], ['pid' => getmypid(), 'done' => false]);
745                 self::$db_duration += (microtime(true) - $stamp);
746                 if (DBA::isResult($r)) {
747                         return DBA::toArray($r);
748                 }
749                 DBA::close($r);
750
751                 return false;
752         }
753
754         /**
755          * @brief Returns the next jobs that should be executed
756          *
757          * @return array array with next jobs
758          * @throws \Exception
759          */
760         private static function nextProcess()
761         {
762                 $priority = self::nextPriority();
763                 if (empty($priority)) {
764                         Logger::info('No tasks found');
765                         return [];
766                 }
767
768                 if ($priority <= PRIORITY_MEDIUM) {
769                         $limit = Config::get('system', 'worker_fetch_limit', 1);
770                 } else {
771                         $limit = 1;
772                 }
773
774                 $ids = [];
775                 $stamp = (float)microtime(true);
776                 $condition = ["`priority` = ? AND `pid` = 0 AND NOT `done` AND `next_try` < ?", $priority, DateTimeFormat::utcNow()];
777                 $tasks = DBA::select('workerqueue', ['id'], $condition, ['limit' => $limit, 'order' => ['created']]);
778                 self::$db_duration += (microtime(true) - $stamp);
779                 while ($task = DBA::fetch($tasks)) {
780                         $ids[] = $task['id'];
781                 }
782                 DBA::close($tasks);
783
784                 Logger::info('Found:', ['id' => $ids, 'priority' => $priority]);
785                 return $ids;
786         }
787
788         /**
789          * @brief Returns the priority of the next workerqueue job
790          *
791          * @return string priority
792          * @throws \Exception
793          */
794         private static function nextPriority()
795         {
796                 $waiting = [];
797                 $priorities = [PRIORITY_CRITICAL, PRIORITY_HIGH, PRIORITY_MEDIUM, PRIORITY_LOW, PRIORITY_NEGLIGIBLE];
798                 foreach ($priorities as $priority) {
799                         $stamp = (float)microtime(true);
800                         if (DBA::exists('workerqueue', ["`priority` = ? AND `pid` = 0 AND NOT `done` AND `next_try` < ?", $priority, DateTimeFormat::utcNow()])) {
801                                 $waiting[$priority] = true;
802                         }
803                         self::$db_duration += (microtime(true) - $stamp);
804                 }
805
806                 if (!empty($waiting[PRIORITY_CRITICAL])) {
807                         return PRIORITY_CRITICAL;
808                 }
809
810                 $running = [];
811                 $running_total = 0;
812                 $stamp = (float)microtime(true);
813                 $processes = DBA::p("SELECT COUNT(DISTINCT(`process`.`pid`)) AS `running`, `priority` FROM `process`
814                         INNER JOIN `workerqueue` ON `workerqueue`.`pid` = `process`.`pid`
815                         WHERE NOT `done` GROUP BY `priority`");
816                 self::$db_duration += (microtime(true) - $stamp);
817                 while ($process = DBA::fetch($processes)) {
818                         $running[$process['priority']] = $process['running'];
819                         $running_total += $process['running'];
820                 }
821                 DBA::close($processes);
822
823                 foreach ($priorities as $priority) {
824                         if (!empty($waiting[$priority]) && empty($running[$priority])) {
825                                 Logger::info('No running worker found with priority {priority} - assigning it.', ['priority' => $priority]);
826                                 return $priority;
827                         }
828                 }
829
830                 $active = max(self::activeWorkers(), $running_total);
831                 $priorities = max(count($waiting), count($running));
832                 $exponent = 2;
833
834                 $total = 0;
835                 for ($i = 1; $i <= $priorities; ++$i) {
836                         $total += pow($i, $exponent);
837                 }
838
839                 $limit = [];
840                 for ($i = 1; $i <= $priorities; ++$i) {
841                         $limit[$priorities - $i] = max(1, round($active * (pow($i, $exponent) / $total)));
842                 }
843
844                 $i = 0;
845                 foreach ($running as $priority => $workers) {
846                         if ($workers < $limit[$i++]) {
847                                 Logger::info('Priority {priority} has got {workers} workers out of a limit of {limit}', ['priority' => $priority, 'workers' => $workers, 'limit' => $limit[$i - 1]]);
848                                 return $priority;
849                         }
850                 }
851
852                 if (!empty($waiting)) {
853                         $priority =  array_shift(array_keys($waiting));
854                         Logger::info('No underassigned priority found, now taking the highest priority.', ['priority' => $priority]);
855                         return $priority;
856                 }
857
858                 return false;
859         }
860
861         /**
862          * @brief Find and claim the next worker process for us
863          *
864          * @return boolean Have we found something?
865          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
866          */
867         private static function findWorkerProcesses()
868         {
869                 $mypid = getmypid();
870
871                 $ids = self::nextProcess();
872
873                 // If there is no result we check without priority limit
874                 if (empty($ids)) {
875                         $stamp = (float)microtime(true);
876                         $condition = ["`pid` = 0 AND NOT `done` AND `next_try` < ?", DateTimeFormat::utcNow()];
877                         $result = DBA::select('workerqueue', ['id'], $condition, ['limit' => 1, 'order' => ['priority', 'created']]);
878                         self::$db_duration += (microtime(true) - $stamp);
879
880                         while ($id = DBA::fetch($result)) {
881                                 $ids[] = $id["id"];
882                         }
883                         DBA::close($result);
884                 }
885
886                 if (!empty($ids)) {
887                         $stamp = (float)microtime(true);
888                         $condition = ['id' => $ids, 'done' => false, 'pid' => 0];
889                         DBA::update('workerqueue', ['executed' => DateTimeFormat::utcNow(), 'pid' => $mypid], $condition);
890                         self::$db_duration += (microtime(true) - $stamp);
891                         self::$db_duration_write += (microtime(true) - $stamp);
892                 }
893
894                 return !empty($ids);
895         }
896
897         /**
898          * @brief Returns the next worker process
899          *
900          * @return string SQL statement
901          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
902          */
903         public static function workerProcess()
904         {
905                 // There can already be jobs for us in the queue.
906                 $waiting = self::getWaitingJobForPID();
907                 if (!empty($waiting)) {
908                         return $waiting;
909                 }
910
911                 $stamp = (float)microtime(true);
912                 if (!Lock::acquire('worker_process')) {
913                         return false;
914                 }
915                 self::$lock_duration += (microtime(true) - $stamp);
916
917                 $found = self::findWorkerProcesses();
918
919                 Lock::release('worker_process');
920
921                 if ($found) {
922                         $stamp = (float)microtime(true);
923                         $r = DBA::select('workerqueue', [], ['pid' => getmypid(), 'done' => false]);
924                         self::$db_duration += (microtime(true) - $stamp);
925                         return DBA::toArray($r);
926                 }
927                 return false;
928         }
929
930         /**
931          * @brief Removes a workerqueue entry from the current process
932          * @return void
933          * @throws \Exception
934          */
935         public static function unclaimProcess()
936         {
937                 $mypid = getmypid();
938
939                 $stamp = (float)microtime(true);
940                 DBA::update('workerqueue', ['executed' => DBA::NULL_DATETIME, 'pid' => 0], ['pid' => $mypid, 'done' => false]);
941                 self::$db_duration += (microtime(true) - $stamp);
942                 self::$db_duration_write += (microtime(true) - $stamp);
943         }
944
945         /**
946          * @brief Call the front end worker
947          * @return void
948          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
949          */
950         public static function callWorker()
951         {
952                 if (!Config::get("system", "frontend_worker")) {
953                         return;
954                 }
955
956                 $url = System::baseUrl()."/worker";
957                 Network::fetchUrl($url, false, $redirects, 1);
958         }
959
960         /**
961          * @brief Call the front end worker if there aren't any active
962          * @return void
963          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
964          */
965         public static function executeIfIdle()
966         {
967                 if (!Config::get("system", "frontend_worker")) {
968                         return;
969                 }
970
971                 // Do we have "proc_open"? Then we can fork the worker
972                 if (function_exists("proc_open")) {
973                         // When was the last time that we called the worker?
974                         // Less than one minute? Then we quit
975                         if ((time() - Config::get("system", "worker_started")) < 60) {
976                                 return;
977                         }
978
979                         Config::set("system", "worker_started", time());
980
981                         // Do we have enough running workers? Then we quit here.
982                         if (self::tooMuchWorkers()) {
983                                 // Cleaning dead processes
984                                 self::killStaleWorkers();
985                                 Process::deleteInactive();
986
987                                 return;
988                         }
989
990                         self::runCron();
991
992                         Logger::log('Call worker', Logger::DEBUG);
993                         self::spawnWorker();
994                         return;
995                 }
996
997                 // We cannot execute background processes.
998                 // We now run the processes from the frontend.
999                 // This won't work with long running processes.
1000                 self::runCron();
1001
1002                 self::clearProcesses();
1003
1004                 $workers = self::activeWorkers();
1005
1006                 if ($workers == 0) {
1007                         self::callWorker();
1008                 }
1009         }
1010
1011         /**
1012          * @brief Removes long running worker processes
1013          * @return void
1014          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
1015          */
1016         public static function clearProcesses()
1017         {
1018                 $timeout = Config::get("system", "frontend_worker_timeout", 10);
1019
1020                 /// @todo We should clean up the corresponding workerqueue entries as well
1021                 $stamp = (float)microtime(true);
1022                 $condition = ["`created` < ? AND `command` = 'worker.php'",
1023                                 DateTimeFormat::utc("now - ".$timeout." minutes")];
1024                 DBA::delete('process', $condition);
1025                 self::$db_duration = (microtime(true) - $stamp);
1026                 self::$db_duration_write += (microtime(true) - $stamp);
1027         }
1028
1029         /**
1030          * @brief Runs the cron processes
1031          * @return void
1032          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
1033          */
1034         private static function runCron()
1035         {
1036                 Logger::log('Add cron entries', Logger::DEBUG);
1037
1038                 // Check for spooled items
1039                 self::add(['priority' => PRIORITY_HIGH, 'force_priority' => true], 'SpoolPost');
1040
1041                 // Run the cron job that calls all other jobs
1042                 self::add(['priority' => PRIORITY_MEDIUM, 'force_priority' => true], 'Cron');
1043
1044                 // Cleaning dead processes
1045                 self::killStaleWorkers();
1046         }
1047
1048         /**
1049          * @brief Spawns a new worker
1050          * @param bool $do_cron
1051          * @return void
1052          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
1053          */
1054         public static function spawnWorker($do_cron = false)
1055         {
1056                 $command = 'bin/worker.php';
1057
1058                 $args = ['no_cron' => !$do_cron];
1059
1060                 get_app()->proc_run($command, $args);
1061
1062                 // after spawning we have to remove the flag.
1063                 if (Config::get('system', 'worker_daemon_mode', false)) {
1064                         self::IPCSetJobState(false);
1065                 }
1066         }
1067
1068         /**
1069          * @brief Adds tasks to the worker queue
1070          *
1071          * @param (integer|array) priority or parameter array, strings are deprecated and are ignored
1072          *
1073          * next args are passed as $cmd command line
1074          * or: Worker::add(PRIORITY_HIGH, "Notifier", "drop", $drop_id);
1075          * or: Worker::add(array('priority' => PRIORITY_HIGH, 'dont_fork' => true), "CreateShadowEntry", $post_id);
1076          *
1077          * @return boolean "false" if proc_run couldn't be executed
1078          * @throws \Friendica\Network\HTTPException\InternalServerErrorException
1079          * @note $cmd and string args are surrounded with ""
1080          *
1081          * @hooks 'proc_run'
1082          *    array $arr
1083          *
1084          */
1085         public static function add($cmd)
1086         {
1087                 $args = func_get_args();
1088
1089                 if (!count($args)) {
1090                         return false;
1091                 }
1092
1093                 $arr = ['args' => $args, 'run_cmd' => true];
1094
1095                 Hook::callAll("proc_run", $arr);
1096                 if (!$arr['run_cmd'] || !count($args)) {
1097                         return true;
1098                 }
1099
1100                 $priority = PRIORITY_MEDIUM;
1101                 $dont_fork = Config::get("system", "worker_dont_fork", false);
1102                 $created = DateTimeFormat::utcNow();
1103                 $force_priority = false;
1104
1105                 $run_parameter = array_shift($args);
1106
1107                 if (is_int($run_parameter)) {
1108                         $priority = $run_parameter;
1109                 } elseif (is_array($run_parameter)) {
1110                         if (isset($run_parameter['priority'])) {
1111                                 $priority = $run_parameter['priority'];
1112                         }
1113                         if (isset($run_parameter['created'])) {
1114                                 $created = $run_parameter['created'];
1115                         }
1116                         if (isset($run_parameter['dont_fork'])) {
1117                                 $dont_fork = $run_parameter['dont_fork'];
1118                         }
1119                         if (isset($run_parameter['force_priority'])) {
1120                                 $force_priority = $run_parameter['force_priority'];
1121                         }
1122                 }
1123
1124                 $parameters = json_encode($args);
1125                 $found = DBA::exists('workerqueue', ['parameter' => $parameters, 'done' => false]);
1126
1127                 // Quit if there was a database error - a precaution for the update process to 3.5.3
1128                 if (DBA::errorNo() != 0) {
1129                         return false;
1130                 }
1131
1132                 if (!$found) {
1133                         DBA::insert('workerqueue', ['parameter' => $parameters, 'created' => $created, 'priority' => $priority]);
1134                 } elseif ($force_priority) {
1135                         DBA::update('workerqueue', ['priority' => $priority], ['parameter' => $parameters, 'done' => false, 'pid' => 0]);
1136                 }
1137
1138                 // Should we quit and wait for the worker to be called as a cronjob?
1139                 if ($dont_fork) {
1140                         return true;
1141                 }
1142
1143                 // If there is a lock then we don't have to check for too much worker
1144                 if (!Lock::acquire('worker', 0)) {
1145                         return true;
1146                 }
1147
1148                 // If there are already enough workers running, don't fork another one
1149                 $quit = self::tooMuchWorkers();
1150                 Lock::release('worker');
1151
1152                 if ($quit) {
1153                         return true;
1154                 }
1155
1156                 // We tell the daemon that a new job entry exists
1157                 if (Config::get('system', 'worker_daemon_mode', false)) {
1158                         // We don't have to set the IPC flag - this is done in "tooMuchWorkers"
1159                         return true;
1160                 }
1161
1162                 // Now call the worker to execute the jobs that we just added to the queue
1163                 self::spawnWorker();
1164
1165                 return true;
1166         }
1167
1168         /**
1169          * Defers the current worker entry
1170          */
1171         public static function defer()
1172         {
1173                 if (empty(BaseObject::getApp()->queue)) {
1174                         return;
1175                 }
1176
1177                 $queue = BaseObject::getApp()->queue;
1178
1179                 $retrial = $queue['retrial'];
1180                 $id = $queue['id'];
1181                 $priority = $queue['priority'];
1182
1183                 if ($retrial > 14) {
1184                         Logger::log('Id ' . $id . ' had been tried 14 times. We stop now.', Logger::DEBUG);
1185                         return;
1186                 }
1187
1188                 // Calculate the delay until the next trial
1189                 $delay = (($retrial + 3) ** 4) + (rand(1, 30) * ($retrial + 1));
1190                 $next = DateTimeFormat::utc('now + ' . $delay . ' seconds');
1191
1192                 if (($priority < PRIORITY_MEDIUM) && ($retrial > 2)) {
1193                         $priority = PRIORITY_MEDIUM;
1194                 } elseif (($priority < PRIORITY_LOW) && ($retrial > 5)) {
1195                         $priority = PRIORITY_LOW;
1196                 } elseif (($priority < PRIORITY_NEGLIGIBLE) && ($retrial > 7)) {
1197                         $priority = PRIORITY_NEGLIGIBLE;
1198                 }
1199
1200                 Logger::log('Defer execution ' . $retrial . ' of id ' . $id . ' to ' . $next . ' - priority old/new: ' . $queue['priority'] . '/' . $priority, Logger::DEBUG);
1201
1202                 $stamp = (float)microtime(true);
1203                 $fields = ['retrial' => $retrial + 1, 'next_try' => $next, 'executed' => DBA::NULL_DATETIME, 'pid' => 0, 'priority' => $priority];
1204                 DBA::update('workerqueue', $fields, ['id' => $id]);
1205                 self::$db_duration += (microtime(true) - $stamp);
1206                 self::$db_duration_write += (microtime(true) - $stamp);
1207         }
1208
1209         /**
1210          * Log active processes into the "process" table
1211          *
1212          * @brief Log active processes into the "process" table
1213          */
1214         public static function startProcess()
1215         {
1216                 $trace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 1);
1217
1218                 $command = basename($trace[0]['file']);
1219
1220                 Process::deleteInactive();
1221
1222                 Process::insert($command);
1223         }
1224
1225         /**
1226          * Remove the active process from the "process" table
1227          *
1228          * @brief Remove the active process from the "process" table
1229          * @return bool
1230          * @throws \Exception
1231          */
1232         public static function endProcess()
1233         {
1234                 return Process::deleteByPid();
1235         }
1236
1237         /**
1238          * Set the flag if some job is waiting
1239          *
1240          * @brief Set the flag if some job is waiting
1241          * @param boolean $jobs Is there a waiting job?
1242          * @throws \Exception
1243          */
1244         public static function IPCSetJobState($jobs)
1245         {
1246                 $stamp = (float)microtime(true);
1247                 DBA::update('worker-ipc', ['jobs' => $jobs], ['key' => 1], true);
1248                 self::$db_duration += (microtime(true) - $stamp);
1249                 self::$db_duration_write += (microtime(true) - $stamp);
1250         }
1251
1252         /**
1253          * Checks if some worker job waits to be executed
1254          *
1255          * @brief Checks if some worker job waits to be executed
1256          * @return bool
1257          * @throws \Exception
1258          */
1259         public static function IPCJobsExists()
1260         {
1261                 $stamp = (float)microtime(true);
1262                 $row = DBA::selectFirst('worker-ipc', ['jobs'], ['key' => 1]);
1263                 self::$db_duration += (microtime(true) - $stamp);
1264
1265                 // When we don't have a row, no job is running
1266                 if (!DBA::isResult($row)) {
1267                         return false;
1268                 }
1269
1270                 return (bool)$row['jobs'];
1271         }
1272 }