diff --git a/lib/classes/module/console/schedulerStart.php b/lib/classes/module/console/schedulerStart.php index 8182492348..c0c90a0288 100644 --- a/lib/classes/module/console/schedulerStart.php +++ b/lib/classes/module/console/schedulerStart.php @@ -42,7 +42,7 @@ class module_console_schedulerStart extends Command $logger->pushHandler($streamHandler); $logfile = __DIR__ . '/../../../../logs/scheduler.log'; - $rotateHandler = new Handler\RotatingFileHandler($logfile, 10); + $rotateHandler = new Handler\RotatingFileHandler($logfile, 10, Logger::INFO); $logger->pushHandler($rotateHandler); try { diff --git a/lib/classes/module/console/taskrun.php b/lib/classes/module/console/taskrun.php index 6a40782584..a78ff818c0 100644 --- a/lib/classes/module/console/taskrun.php +++ b/lib/classes/module/console/taskrun.php @@ -18,6 +18,7 @@ use Symfony\Component\Console\Output\OutputInterface; use Monolog\Handler; use Monolog\Handler\StreamHandler; use Monolog\Handler\RotatingFileHandler; +use Monolog\Logger; /** * @todo write tests @@ -96,7 +97,7 @@ class module_console_taskrun extends Command } $logfile = __DIR__ . '/../../../../logs/task_' . $task_id . '.log'; - $this->container['task-manager.logger']->pushHandler(new RotatingFileHandler($logfile, 10)); + $this->container['task-manager.logger']->pushHandler(new RotatingFileHandler($logfile, 10, Logger::INFO)); $this->task = $task_manager->getTask($task_id, $this->container['task-manager.logger']); $lib2v = array( diff --git a/lib/classes/task/Scheduler.php b/lib/classes/task/Scheduler.php index f02aa42fa7..7795ee304d 100644 --- a/lib/classes/task/Scheduler.php +++ b/lib/classes/task/Scheduler.php @@ -45,9 +45,9 @@ class task_Scheduler $this->schedstatus = ''; } - protected function log($message) + protected function log($message, $level = Logger::DEBUG) { - $this->logger->addInfo($message); + $this->logger->addRecord($level, $message); return $this; } @@ -114,7 +114,7 @@ class task_Scheduler $lockfile = ($lockdir . 'scheduler.lock'); if (($schedlock = fopen($lockfile, 'a+')) != FALSE) { if (flock($schedlock, LOCK_EX | LOCK_NB) === FALSE) { - $this->log(sprintf("failed to lock '%s' (try=%s/4)", $lockfile, $try)); + $this->log(sprintf("failed to lock '%s' (try=%s/4)", $lockfile, $try), Logger::INFO); if ($try == 4) { $this->log("scheduler already running."); fclose($schedlock); @@ -140,7 +140,7 @@ class task_Scheduler } } - $this->log(sprintf("running scheduler with method %s", $this->method)); + $this->log(sprintf("running scheduler with method %s", $this->method), Logger::INFO); $conn = $this->dependencyContainer['phraseanet.appbox']->get_connection(); @@ -182,7 +182,7 @@ class task_Scheduler unset($conn); if (! $connwaslost) { - $this->log(sprintf("Warning : abox connection lost, restarting in 10 min.")); + $this->log(sprintf("Warning : abox connection lost, restarting in 10 min."), Logger::INFO); } for ($i = 0; $i < 60 * 10; $i ++) { sleep(1); @@ -196,7 +196,7 @@ class task_Scheduler $connwaslost = true; } if ($connwaslost) { - $this->log("abox connection restored"); + $this->log("abox connection restored", Logger::INFO); $sql = 'UPDATE task SET crashed=0'; $stmt = $conn->prepare($sql); @@ -235,7 +235,7 @@ class task_Scheduler $stmt = $conn->prepare($sql); $stmt->execute(); $stmt->closeCursor(); - $this->log("schedstatus == 'stopping', waiting tasks to end"); + $this->log("schedstatus == 'stopping', waiting tasks to end", Logger::INFO); } // initialy, all tasks are supposed to be removed from the poll @@ -490,7 +490,7 @@ class task_Scheduler "Task %s crashed %d times" , $taskPoll[$tkey]["task"]->getID() , $taskPoll[$tkey]["task"]->getCrashCounter() - ) + ), Logger::INFO ); if ($taskPoll[$tkey]["task"]->getCrashCounter() > 5) { @@ -519,7 +519,7 @@ class task_Scheduler "SIGTERM sent to task %s (pid=%s)" , $taskPoll[$tkey]["task"]->getID() , $pid - ) + ), Logger::INFO ); } } @@ -536,7 +536,7 @@ class task_Scheduler "proc_terminate(...) done on task %s (pid=%s)" , $taskPoll[$tkey]["task"]->getID() , $pid - ) + ), Logger::INFO ); } else { // METHOD_FORK, I guess we have posix posix_kill($pid, 9); @@ -545,7 +545,7 @@ class task_Scheduler "SIGKILL sent to task %s (pid=%s)" , $taskPoll[$tkey]["task"]->getID() , $pid - ) + ), Logger::INFO ); } } else { @@ -554,7 +554,7 @@ class task_Scheduler "waiting task %s to quit (kill in %d seconds)" , $taskPoll[$tkey]["task"]->getID() , $dt - ) + ), Logger::INFO ); $runningtask ++; } @@ -563,7 +563,7 @@ class task_Scheduler sprintf( "task %s has quit" , $taskPoll[$tkey]["task"]->getID() - ) + ), Logger::INFO ); $taskPoll[$tkey]["task"]->setState(task_abstract::STATE_STOPPED); } @@ -610,11 +610,11 @@ class task_Scheduler $stmt->execute(); $stmt->closeCursor(); - $this->log("Scheduler2 is quitting."); + $this->log("Scheduler2 is quitting.", Logger::INFO); ftruncate($schedlock, 0); fclose($schedlock); - $this->log("Scheduler2 has quit.\n"); + $this->log("Scheduler2 has quit.\n", Logger::INFO); } } diff --git a/lib/classes/task/abstract.php b/lib/classes/task/abstract.php index 154f3de0d1..198a074db9 100644 --- a/lib/classes/task/abstract.php +++ b/lib/classes/task/abstract.php @@ -136,8 +136,7 @@ abstract class task_abstract try { $conn = connection::getPDOConnection($this->dependencyContainer); } catch (Exception $e) { - $this->log($e->getMessage()); - $this->log(("Warning : abox connection lost, restarting in 10 min.")); + $this->log(("Warning : abox connection lost : ".$e->getMessage().", restarting in 10 min."), self::LOG_DEBUG); $this->sleep(60 * 10); @@ -252,7 +251,7 @@ abstract class task_abstract $stmt = $conn->prepare($sql); $stmt->execute(array(':status' => $status, ':taskid' => $this->getID())); $stmt->closeCursor(); - $this->log(sprintf("task %d <- %s", $this->getID(), $status)); + $this->log(sprintf("task %d <- %s", $this->getID(), $status), self::LOG_INFO); } /** @@ -542,7 +541,9 @@ abstract class task_abstract protected function pause($when_started = 0) { - $this->log($this->records_done . ' records done'); + if ($this->records_done > 0) { + $this->log($this->records_done . ' records done'); + } if ($this->running) { // && $this->records_done == 0) $when_started = time() - $when_started; if ($when_started < $this->period) { @@ -602,7 +603,7 @@ abstract class task_abstract $locker = true; if (flock($lockFD, LOCK_EX | LOCK_NB, $locker) === FALSE) { - $this->log("runtask::ERROR : task already running."); + $this->log("runtask::ERROR : task already running.", self::LOG_ERROR); fclose($lockFD); throw new Exception('task already running.', self::ERR_ALREADY_RUNNING); @@ -691,7 +692,7 @@ abstract class task_abstract // process one record $this->processOneContent($box, $row); } catch (Exception $e) { - $this->log("Exception : " . $e->getMessage() . " " . basename($e->getFile()) . " " . $e->getLine()); + $this->log("Exception : " . $e->getMessage() . " " . basename($e->getFile()) . " " . $e->getLine(), self::LOG_ERROR); } $this->records_done ++; @@ -704,13 +705,13 @@ abstract class task_abstract $current_memory = memory_get_usage(); if ($current_memory >> 20 >= $this->maxmegs) { - $this->log(sprintf("Max memory (%s M) reached (actual is %.02f M)", $this->maxmegs, ($current_memory >> 10) / 1024), self::LOG_ERROR); + $this->log(sprintf("Max memory (%s M) reached (actual is %.02f M)", $this->maxmegs, ($current_memory >> 10) / 1024), self::LOG_DEBUG); $this->running = FALSE; $ret = self::STATE_MAXMEGSREACHED; } if ($this->records_done >= (integer) ($this->maxrecs)) { - $this->log(sprintf("Max records done (%s) reached (actual is %s)", $this->maxrecs, $this->records_done)); + $this->log(sprintf("Max records done (%s) reached (actual is %s)", $this->maxrecs, $this->records_done), self::LOG_DEBUG); $this->running = FALSE; $ret = self::STATE_MAXRECSDONE; } @@ -789,7 +790,7 @@ abstract class task_abstract protected function incrementLoops() { if ($this->getRunner() == self::RUNNER_SCHEDULER && ++ $this->loop >= $this->maxloops) { - $this->log(sprintf(('%d loops done, restarting'), $this->loop)); + $this->log(sprintf(('%d loops done, restarting'), $this->loop), self::LOG_DEBUG); $this->setState(self::STATE_TORESTART); $this->running = false; @@ -812,9 +813,8 @@ abstract class task_abstract $this->logger->addDebug(memory_get_usage() . " -- " . memory_get_usage(true)); } - public function log($message, $level=self::LOG_INFO) + public function log($message, $level = Logger::LOG_DEBUG) { - // nb : self::log_levels ARE standard log levels, ok with monolog $this->logger->addRecord($level, $message); return $this; diff --git a/lib/classes/task/databoxAbstract.php b/lib/classes/task/databoxAbstract.php index a2be8b0544..79cc6e8e0e 100644 --- a/lib/classes/task/databoxAbstract.php +++ b/lib/classes/task/databoxAbstract.php @@ -82,7 +82,7 @@ abstract class task_databoxAbstract extends task_abstract } $this->sbas_id = (int) $row['sbas_id']; - $this->log(sprintf('This task works now on sbasid=%s ', $this->sbas_id), self::LOG_INFO); + $this->log(sprintf('This task works now on sbasid=%s ', $this->sbas_id), self::LOG_DEBUG); try { // get the records to process