Switch task manager logging to monolog

This commit is contained in:
Romain Neutron
2012-05-24 14:04:33 +02:00
parent 8b43e36532
commit 3c2d16fd00
8 changed files with 88 additions and 98 deletions

View File

@@ -15,6 +15,8 @@
* @license http://opensource.org/licenses/gpl-3.0 GPLv3 * @license http://opensource.org/licenses/gpl-3.0 GPLv3
* @link www.phraseanet.com * @link www.phraseanet.com
*/ */
use Monolog\Handler;
use Monolog\Logger;
use Symfony\Component\Console\Input\InputInterface; use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Input\InputOption; use Symfony\Component\Console\Input\InputOption;
use Symfony\Component\Console\Output\OutputInterface; use Symfony\Component\Console\Output\OutputInterface;
@@ -28,25 +30,6 @@ class module_console_schedulerStart extends Command
parent::__construct($name); parent::__construct($name);
$this->setDescription('Start the scheduler'); $this->setDescription('Start the scheduler');
$this->addOption(
'nolog'
, NULL
, 1 | InputOption::VALUE_NONE
, 'do not log (scheduler) to logfile'
, NULL
);
$this->addOption(
'notasklog'
, NULL
, 1 | InputOption::VALUE_NONE
, 'do not log (tasks) to logfiles'
, NULL
);
$this->setHelp(
"You should use launch the command and finish it with `&`"
. " to return to the console\n\n"
. "\tie : <info>bin/console scheduler:start &</info>"
);
return $this; return $this;
} }
@@ -59,9 +42,18 @@ class module_console_schedulerStart extends Command
return 1; return 1;
} }
$logger = new Logger('Task logger');
$handler = new Handler\StreamHandler(fopen('php://stdout'), $input->getOption('verbose') ? Logger::DEBUG : Logger::WARNING);
$logger->pushHandler($handler);
$logfile = __DIR__ . '/../../../../scheduler.log';
$handler = new Handler\RotatingFileHandler($logfile, 10, $level = Logger::WARNING);
$logger->pushHandler($handler);
try { try {
$scheduler = new task_Scheduler(); $scheduler = new task_Scheduler();
$scheduler->run($input, $output); $scheduler->run($logger);
} catch (\Exception $e) { } catch (\Exception $e) {
switch ($e->getCode()) { switch ($e->getCode()) {
case task_Scheduler::ERR_ALREADY_RUNNING: // 114 : aka EALREADY (Operation already in progress) case task_Scheduler::ERR_ALREADY_RUNNING: // 114 : aka EALREADY (Operation already in progress)

View File

@@ -9,17 +9,20 @@
* file that was distributed with this source code. * file that was distributed with this source code.
*/ */
use Monolog\Handler;
use Monolog\Logger;
use Symfony\Component\Console\Input\InputArgument;
use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Input\InputOption;
use Symfony\Component\Console\Output\OutputInterface;
use Symfony\Component\Console\Command\Command;
/** /**
* @todo write tests * @todo write tests
* *
* @license http://opensource.org/licenses/gpl-3.0 GPLv3 * @license http://opensource.org/licenses/gpl-3.0 GPLv3
* @link www.phraseanet.com * @link www.phraseanet.com
*/ */
use Symfony\Component\Console\Input\InputArgument;
use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Input\InputOption;
use Symfony\Component\Console\Output\OutputInterface;
use Symfony\Component\Console\Command\Command;
class module_console_taskrun extends Command class module_console_taskrun extends Command
{ {
@@ -95,14 +98,26 @@ class module_console_taskrun extends Command
} }
} }
$logger = new Logger('Task logger');
if ($input->getOption('verbose')) {
$handler = new Handler\StreamHandler(fopen('php://stdout', 'a'));
$logger->pushHandler($handler);
}
$logfile = __DIR__ . '/../../../../task_l_' . $task_id . '.log';
$handler = new Handler\RotatingFileHandler($logfile, 10, $level = Logger::WARNING);
$logger->pushHandler($handler);
register_tick_function(array($this, 'tick_handler'), true); register_tick_function(array($this, 'tick_handler'), true);
declare(ticks = 1); declare(ticks = 1);
if (function_exists('pcntl_signal')) { if (function_exists('pcntl_signal')) {
pcntl_signal(SIGTERM, array($this, 'sig_handler')); pcntl_signal(SIGTERM, array($this, 'sig_handler'));
} }
try { try {
$this->task->run($runner, $input, $output); $this->task->run($runner, $logger);
} catch (Exception $e) { } catch (Exception $e) {
$this->task->log(sprintf("taskrun : exception from 'run()', %s \n", $e->getMessage())); $this->task->log(sprintf("taskrun : exception from 'run()', %s \n", $e->getMessage()));

View File

@@ -10,6 +10,7 @@
*/ */
use MediaVorus\Media\Media; use MediaVorus\Media\Media;
use Monolog\Logger;
/** /**
* *
@@ -99,7 +100,7 @@ interface record_Interface
public function delete(); public function delete();
public function generate_subdefs(databox $databox, Array $wanted_subdefs = null); public function generate_subdefs(databox $databox, Logger $logger = null, Array $wanted_subdefs = null);
public function log_view($log_id, $referrer, $gv_sit); public function log_view($log_id, $referrer, $gv_sit);

View File

@@ -9,6 +9,7 @@
* file that was distributed with this source code. * file that was distributed with this source code.
*/ */
use Monolog\Logger;
use MediaVorus\Media\Media; use MediaVorus\Media\Media;
use Symfony\Component\HttpFoundation\File\File as SymfoFile; use Symfony\Component\HttpFoundation\File\File as SymfoFile;
@@ -1647,15 +1648,23 @@ class record_adapter implements record_Interface, cache_cacheableInterface
} }
/** /**
* Generates subdefs
* *
* @param databox $databox * @param databox $databox The databox
* @param \Monolog\Logger $logger A logger for binary operation
* @param array $wanted_subdefs An array of subdef names
* @return \record_adapter
*/ */
public function generate_subdefs(databox $databox, Array $wanted_subdefs = null) public function generate_subdefs(databox $databox, Logger $logger = null, Array $wanted_subdefs = null)
{ {
$subdefs = $databox->get_subdef_structure()->getSubdefGroup($this->get_type()); $subdefs = $databox->get_subdef_structure()->getSubdefGroup($this->get_type());
$Core = bootstrap::getCore(); $Core = bootstrap::getCore();
if ( ! $logger) {
$logger = $Core['monolog'];
}
if ( ! $subdefs) { if ( ! $subdefs) {
$Core['monolog']->addInfo(sprintf('Nothing to do for %s', $this->get_type())); $Core['monolog']->addInfo(sprintf('Nothing to do for %s', $this->get_type()));
@@ -1682,7 +1691,7 @@ class record_adapter implements record_Interface, cache_cacheableInterface
$pathdest = $this->generateSubdefPathname($subdef, $pathdest); $pathdest = $this->generateSubdefPathname($subdef, $pathdest);
$this->generate_subdef($subdef, $pathdest); $this->generate_subdef($subdef, $pathdest, $logger);
if (file_exists($pathdest)) { if (file_exists($pathdest)) {
$media = \MediaVorus\MediaVorus::guess(new \SplFileInfo($pathdest)); $media = \MediaVorus\MediaVorus::guess(new \SplFileInfo($pathdest));
@@ -1712,12 +1721,14 @@ class record_adapter implements record_Interface, cache_cacheableInterface
} }
/** /**
* Generate a subdef
* *
* @todo move to media_subdef class * @param databox_subdef $subdef_class The related databox subdef
* @param databox_subdef $subdef_class * @param type $pathdest The destination of the file
* @param string $pathdest * @param Logger $logger A logger for binary operation
* @return \record_adapter
*/ */
protected function generate_subdef(databox_subdef $subdef_class, $pathdest) protected function generate_subdef(databox_subdef $subdef_class, $pathdest, Logger $logger)
{ {
$Core = \bootstrap::getCore(); $Core = \bootstrap::getCore();
@@ -1730,7 +1741,7 @@ class record_adapter implements record_Interface, cache_cacheableInterface
$Core['media-alchemyst']->turnInto($pathdest, $subdef_class->getSpecs()); $Core['media-alchemyst']->turnInto($pathdest, $subdef_class->getSpecs());
$Core['media-alchemyst']->close(); $Core['media-alchemyst']->close();
} catch (\MediaAlchemyst\Exception\Exception $e) { } catch (\MediaAlchemyst\Exception\Exception $e) {
$Core['monolog']->addError(sprintf('Subdef generation failed with message %s', $e->getMessage())); $logger->addError(sprintf('Subdef generation failed for record %d with message %s', $this->get_record_id(), $e->getMessage()));
} }
return $this; return $this;

View File

@@ -26,25 +26,18 @@ class task_Scheduler
const ERR_ALREADY_RUNNING = 114; // aka EALREADY (Operation already in progress) const ERR_ALREADY_RUNNING = 114; // aka EALREADY (Operation already in progress)
/**
*
* @var \Monolog\Logger
*/
private $logger;
private $method; private $method;
private $input; private $input;
protected $output; protected $output;
protected function log($message) protected function log($message)
{ {
$registry = registry::get_instance(); $this->logger->addInfo($message);
$logdir = $registry->get('GV_RootPath') . 'logs/';
logs::rotate($logdir . "scheduler_l.log");
logs::rotate($logdir . "scheduler_o.log");
logs::rotate($logdir . "scheduler_e.log");
$date_obj = new DateTime();
$message = sprintf("%s\t%s", $date_obj->format(DATE_ATOM), $message);
if ($this->input && ! ($this->input->getOption('nolog'))) {
file_put_contents($logdir . "scheduler_l.log", $message . "\n", FILE_APPEND);
}
return $this; return $this;
} }
@@ -58,11 +51,10 @@ class task_Scheduler
* @throws Exception if scheduler is already running * @throws Exception if scheduler is already running
* @todo doc all possible exception * @todo doc all possible exception
*/ */
public function run(InputInterface $input = null, OutputInterface $output = null) public function run(\Monolog\Logger $logger)
{ {
require_once dirname(__FILE__) . '/../../bootstrap.php'; $this->logger = $logger;
$this->input = $input;
$this->output = $output;
$appbox = appbox::get_instance(\bootstrap::getCore()); $appbox = appbox::get_instance(\bootstrap::getCore());
$registry = $appbox->get_registry(); $registry = $appbox->get_registry();
@@ -119,8 +111,6 @@ class task_Scheduler
pcntl_signal(SIGCHLD, SIG_IGN); pcntl_signal(SIGCHLD, SIG_IGN);
} }
$logdir = $registry->get('GV_RootPath') . 'logs/';
$conn = appbox::get_instance(\bootstrap::getCore())->get_connection(); $conn = appbox::get_instance(\bootstrap::getCore())->get_connection();
$taskPoll = array(); // the poll of tasks $taskPoll = array(); // the poll of tasks
@@ -216,10 +206,6 @@ class task_Scheduler
$this->log("schedstatus == 'stopping', waiting tasks to end"); $this->log("schedstatus == 'stopping', waiting tasks to end");
} }
logs::rotate($logdir . "scheduler_t.log");
logs::rotate($logdir . "scheduler_o.log");
logs::rotate($logdir . "scheduler_e.log");
// initialy, all tasks are supposed to be removed from the poll // initialy, all tasks are supposed to be removed from the poll
foreach ($taskPoll as $tkey => $task) { foreach ($taskPoll as $tkey => $task) {
$taskPoll[$tkey]["todel"] = true; $taskPoll[$tkey]["todel"] = true;
@@ -229,10 +215,6 @@ class task_Scheduler
$tkey = "t_" . $task->getID(); $tkey = "t_" . $task->getID();
$status = $task->getState(); $status = $task->getState();
logs::rotate($logdir . "task_t_" . $task->getID() . ".log");
logs::rotate($logdir . "task_o_" . $task->getID() . ".log");
logs::rotate($logdir . "task_e_" . $task->getID() . ".log");
if ( ! isset($taskPoll[$tkey])) { if ( ! isset($taskPoll[$tkey])) {
// the task is not in the poll, add it // the task is not in the poll, add it
$phpcli = $registry->get('GV_cli'); $phpcli = $registry->get('GV_cli');
@@ -240,18 +222,12 @@ class task_Scheduler
case "WINDOWS": case "WINDOWS":
$cmd = $phpcli; $cmd = $phpcli;
$args = array('-f', $registry->get('GV_RootPath') . 'bin/console', '--', '-q', 'task:run', $task->getID(), '--runner=scheduler'); $args = array('-f', $registry->get('GV_RootPath') . 'bin/console', '--', '-q', 'task:run', $task->getID(), '--runner=scheduler');
if ($this->input && ($this->input->getOption('notasklog'))) {
$args[] = 'notasklog';
}
break; break;
default: default:
case "DARWIN": case "DARWIN":
case "LINUX": case "LINUX":
$cmd = $phpcli; $cmd = $phpcli;
$args = array('-f', $registry->get('GV_RootPath') . 'bin/console', '--', '-q', 'task:run', $task->getID(), '--runner=scheduler'); $args = array('-f', $registry->get('GV_RootPath') . 'bin/console', '--', '-q', 'task:run', $task->getID(), '--runner=scheduler');
if ($this->input && ($this->input->getOption('notasklog'))) {
$args[] = 'notasklog';
}
break; break;
} }
@@ -344,8 +320,10 @@ class task_Scheduler
if ($this->method == self::METHOD_PROC_OPEN) { if ($this->method == self::METHOD_PROC_OPEN) {
if ( ! $taskPoll[$tkey]["process"]) { if ( ! $taskPoll[$tkey]["process"]) {
$descriptors[1] = array('file', $logdir . "task_o_" . $taskPoll[$tkey]['task']->getID() . ".log", 'a+'); $tmpFile = tempnam(sys_get_temp_dir(), 'task');
$descriptors[2] = array('file', $logdir . "task_e_" . $taskPoll[$tkey]['task']->getID() . ".log", 'a+');
$descriptors[1] = array('file', $tmpFile, 'a+');
$descriptors[2] = array('file', $tmpFile, 'a+');
$taskPoll[$tkey]["process"] = proc_open( $taskPoll[$tkey]["process"] = proc_open(
$taskPoll[$tkey]["cmd"] . ' ' . implode(' ', $taskPoll[$tkey]["args"]) $taskPoll[$tkey]["cmd"] . ' ' . implode(' ', $taskPoll[$tkey]["args"])

View File

@@ -1,5 +1,7 @@
<?php <?php
use Monolog\Logger;
abstract class task_abstract abstract class task_abstract
{ {
const LAUCHED_BY_BROWSER = 1; const LAUCHED_BY_BROWSER = 1;
@@ -19,6 +21,11 @@ abstract class task_abstract
const SIGNAL_SCHEDULER_DIED = 'SIGNAL_SCHEDULER_DIED'; const SIGNAL_SCHEDULER_DIED = 'SIGNAL_SCHEDULER_DIED';
const ERR_ALREADY_RUNNING = 114; // aka EALREADY (Operation already in progress) const ERR_ALREADY_RUNNING = 114; // aka EALREADY (Operation already in progress)
/**
*
* @var Logger
*/
protected $logger;
protected $suicidable = false; protected $suicidable = false;
protected $launched_by = 0; protected $launched_by = 0;
@@ -113,7 +120,7 @@ abstract class task_abstract
return $row['status']; return $row['status'];
} }
/* /**
* to be overwritten by tasks : echo text to be included in <head> in task interface * to be overwritten by tasks : echo text to be included in <head> in task interface
*/ */
public function printInterfaceHEAD() public function printInterfaceHEAD()
@@ -121,7 +128,7 @@ abstract class task_abstract
return false; return false;
} }
/* /**
* to be overwritten by tasks : echo javascript to be included in <head> in task interface * to be overwritten by tasks : echo javascript to be included in <head> in task interface
*/ */
public function printInterfaceJS() public function printInterfaceJS()
@@ -139,9 +146,9 @@ abstract class task_abstract
} }
/** /**
* *
* @return boolean * @return boolean
*/ */
public function getGraphicForm() public function getGraphicForm()
{ {
return false; return false;
@@ -489,10 +496,9 @@ abstract class task_abstract
return $lockFD; return $lockFD;
} }
final public function run($runner, $input = null, $output = null) final public function run($runner, $logger)
{ {
$this->input = $input; $this->logger = $logger;
$this->output = $output;
$lockFD = $this->lockTask(); $lockFD = $this->lockTask();
@@ -503,7 +509,7 @@ abstract class task_abstract
$exception = NULL; $exception = NULL;
try { try {
$this->run2(); $this->run2();
} catch (Exception $exception) { } catch (\Exception $exception) {
} }
@@ -669,27 +675,12 @@ abstract class task_abstract
$d = debug_backtrace(false); $d = debug_backtrace(false);
$lastt = $t; $lastt = $t;
echo "\n" . memory_get_usage() . " -- " . memory_get_usage(true) . "\n"; $this->logger->addDebug(memory_get_usage() . " -- " . memory_get_usage(true));
} }
public function log($message) public function log($message)
{ {
$registry = registry::get_instance(); $this->logger->addInfo($message);
$logdir = $registry->get('GV_RootPath') . 'logs/';
logs::rotate($logdir . 'task_l_' . $this->taskid . '.log');
logs::rotate($logdir . 'task_o_' . $this->taskid . '.log');
logs::rotate($logdir . 'task_e_' . $this->taskid . '.log');
$date_obj = new DateTime();
$message = sprintf("%s\t%s", $date_obj->format(DATE_ATOM), $message);
if ($this->output) {
$this->output->writeln($message);
}
if ($this->input && ! ($this->input->getOption('nolog'))) {
file_put_contents($logdir . 'task_l_' . $this->taskid . '.log', $message . "\n", FILE_APPEND);
}
return $this; return $this;
} }

View File

@@ -169,6 +169,8 @@
<link type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/minify/f=include/jslibs/yui2.8/build/reset/reset.css,include/jslibs/jquery.contextmenu.css,include/jslibs/colorpicker/css/colorpicker.css,include/jslibs/jquery-treeview/jquery.treeview.css,skins/common/main.css,login/geonames.css,include/jquery.image_enhancer.css,include/jslibs/jquery-ui-1.8.17/css/dark-hive/jquery-ui-1.8.17.custom.css" > <link type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/minify/f=include/jslibs/yui2.8/build/reset/reset.css,include/jslibs/jquery.contextmenu.css,include/jslibs/colorpicker/css/colorpicker.css,include/jslibs/jquery-treeview/jquery.treeview.css,skins/common/main.css,login/geonames.css,include/jquery.image_enhancer.css,include/jslibs/jquery-ui-1.8.17/css/dark-hive/jquery-ui-1.8.17.custom.css" >
<link id="skinCss" type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/minify/f=skins/prod/{{cssfile}}/prodcolor.css" > <link id="skinCss" type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/minify/f=skins/prod/{{cssfile}}/prodcolor.css" >
<link type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/minify/f=include/vendor/humane-js/themes/libnotify.css,skins/prod/Prod.css,skins/prod/Basket.css,skins/prod/Push.css" > <link type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/minify/f=include/vendor/humane-js/themes/libnotify.css,skins/prod/Prod.css,skins/prod/Basket.css,skins/prod/Push.css" >
<link type="text/css" rel="stylesheet" href="{{registry.get('GV_STATIC_URL')}}/include/jslibs/video-js/video-js.css">
<!--[if IE 7]> <!--[if IE 7]>
<link type="text/css" rel="stylesheet" href="/include/minify/f=skins/prod/ie7.css" > <link type="text/css" rel="stylesheet" href="/include/minify/f=skins/prod/ie7.css" >
<![endif]--> <![endif]-->
@@ -1089,8 +1091,8 @@
<script type="text/javascript" src="{{registry.get('GV_STATIC_URL')}}/include/jslibs/jquery-ui-1.8.17/js/jquery-ui-1.8.17.custom.min.js"></script> <script type="text/javascript" src="{{registry.get('GV_STATIC_URL')}}/include/jslibs/jquery-ui-1.8.17/js/jquery-ui-1.8.17.custom.min.js"></script>
<script type="text/javascript" src="{{registry.get('GV_STATIC_URL')}}/include/minify/f=include/tinymce/jscripts/tiny_mce/tiny_mce.js"></script> <script type="text/javascript" src="{{registry.get('GV_STATIC_URL')}}/include/minify/f=include/tinymce/jscripts/tiny_mce/tiny_mce.js"></script>
<script type="text/javascript"> <script type="text/javascript">
$(document).ready(function(){ $(document).ready(function(){
_V_.options.flash.swf = "/include/jslibs/video-js/video-js.swf"
p4.reg_delete="{% if user.getPrefs("warning_on_delete_story") %}true{% else %}false{% endif %}"; p4.reg_delete="{% if user.getPrefs("warning_on_delete_story") %}true{% else %}false{% endif %}";
}); });

View File

@@ -180,7 +180,7 @@ class record_adapterTest extends PhraseanetPHPUnitAuthenticatedAbstract
public function testGenerate_subdefs() public function testGenerate_subdefs()
{ {
$this->markTestIncomplete();
} }
public function testGet_sha256() public function testGet_sha256()