class WorkflowTest(unittest.TestCase):
def setUp(self):
# communications channels
parent_workflow_conn, child_workflow_conn = multiprocessing.Pipe()
running_event = multiprocessing.Event()
# logging
log_q = multiprocessing.Queue()
def handle(record):
logger = logging.getLogger(record.name)
if logger.isEnabledFor(record.levelno):
logger.handle(record)
handler = CallbackHandler(handle)
self.queue_listener = QueueListener(log_q, handler)
self.queue_listener.start()
remote_process = multiprocessing.Process(
target=remote_main,
name="remote process",
args=[parent_workflow_conn, log_q, running_event])
remote_process.daemon = True
remote_process.start()
running_event.wait()
self.workflow = LocalWorkflow(child_workflow_conn)
self.remote_process = remote_process
def tearDown(self):
self.workflow.shutdown_remote_process(self.remote_process)
self.queue_listener.stop()
def processes():
ctx = mp.get_context("spawn")
pipes = [mp.Pipe(duplex=True) for _ in [0, 1, 2]]
man = ctx.Manager()
queue = man.Queue()
processes = [Process(target=process_main,
args=(pipes[i][0], queue), ctx=ctx)
for i in [0, 1, 2]]
handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter(
"[%(asctime)s] <%(levelname)s>:%(name)s:%(message)s"))
ql = QueueListener(queue, handler)
ql.start()
default_logger.addHandler(handler)
for p, i in zip(processes, [0, 1, 2]):
default_logger.info("processes {} started".format(i))
p.start()
yield processes, [pi[1] for pi in pipes]
for p, pi, i in zip(processes, pipes, [0, 1, 2]):
# try graceful shutdown first
pi[1].send(dill.dumps((exit, 0, {})))
p.join(timeout=1)
if p.is_alive():
# ungraceful shutdown
default_logger.info("processes {} ungraceful shutdown".format(i))
p.terminate()
p.join()
default_logger.removeHandler(handler)
ql.stop()
man.shutdown()
man.join()
default_logger.info("processes stopped")
class QueueLogger:
def __init__(self):
self.structlog_q = None
self.structlog_q_handler = None
self.structlog_listener = None
self.initialized = False
def initialize_q(self):
self.structlog_q = multiprocessing.Queue(-1)
self.structlog_q_handler = QueueHandler(self.structlog_q)
self.initialized = True
def format_logger(self, logger):
logger.addHandler(self.structlog_q_handler)
def configure_listener(self, handlers):
self.structlog_listener = QueueListener(self.structlog_q, *handlers, respect_handler_level=True)
def setup_queue_logging(self, logger, handlers):
self.initialize_q()
self.format_logger(logger)
self.configure_listener(handlers)
def start(self):
self.structlog_listener.start()
def stop(self):
if self.initialized:
self.structlog_listener.stop()
def test_on_node_error_hook_parallel_runner(self, tmp_path, logging_hooks):
session = KedroSession.create(MOCK_PACKAGE_NAME, tmp_path)
log_records = []
class LogHandler(logging.Handler): # pylint: disable=abstract-method
def handle(self, record):
log_records.append(record)
logs_queue_listener = QueueListener(logging_hooks.queue, LogHandler())
logs_queue_listener.start()
with pytest.raises(ValueError, match="broken"):
try:
session.run(runner=ParallelRunner(max_workers=2),
node_names=["node1", "node2"])
finally:
logs_queue_listener.stop()
on_node_error_records = [
r for r in log_records if r.funcName == "on_node_error"
]
assert len(on_node_error_records) == 2
for call_record in on_node_error_records:
_assert_hook_call_record_has_expected_parameters(
call_record,
["error", "node", "catalog", "inputs", "is_async", "run_id"],
)
expected_error = ValueError("broken")
assert_exceptions_equal(call_record.error, expected_error)
def test_before_and_after_node_run_hooks_are_called_with_parallel_runner(
self, context_with_hooks, dummy_dataframe, logs_queue):
log_records = []
class LogHandler(logging.Handler): # pylint: disable=abstract-method
def handle(self, record):
log_records.append(record)
logs_queue_listener = QueueListener(logs_queue, LogHandler())
logs_queue_listener.start()
context_with_hooks.catalog.save("cars", dummy_dataframe)
context_with_hooks.catalog.save("boats", dummy_dataframe)
context_with_hooks.run(runner=ParallelRunner(),
node_names=["node1", "node2"])
logs_queue_listener.stop()
before_node_run_log_records = [
r for r in log_records if r.funcName == "before_node_run"
]
assert len(before_node_run_log_records) == 2
for record in before_node_run_log_records:
assert record.getMessage() == "About to run node"
assert record.node.name in ["node1", "node2"]
assert set(record.inputs.keys()) <= {"cars", "boats"}
after_node_run_log_records = [
r for r in log_records if r.funcName == "after_node_run"
]
assert len(after_node_run_log_records) == 2
for record in after_node_run_log_records:
assert record.getMessage() == "Ran node"
assert record.node.name in ["node1", "node2"]
assert set(record.outputs.keys()) <= {"planes", "ships"}
def test_on_node_error_hook_is_called_with_parallel_runner(
self, tmp_path, mocker, logging_hooks):
log_records = []
class LogHandler(logging.Handler): # pylint: disable=abstract-method
def handle(self, record):
log_records.append(record)
broken_context_with_hooks = _create_broken_context_with_hooks(
tmp_path, mocker, logging_hooks)
mocker.patch(
"kedro.framework.context.context.load_context",
return_value=broken_context_with_hooks,
)
logs_queue_listener = QueueListener(logging_hooks.queue, LogHandler())
logs_queue_listener.start()
with pytest.raises(ValueError, match="broken"):
broken_context_with_hooks.run(runner=ParallelRunner(max_workers=2),
node_names=["node1", "node2"])
logs_queue_listener.stop()
on_node_error_records = [
r for r in log_records if r.funcName == "on_node_error"
]
assert len(on_node_error_records) == 2
for call_record in on_node_error_records:
self._assert_hook_call_record_has_expected_parameters(
call_record,
["error", "node", "catalog", "inputs", "is_async", "run_id"],
)
expected_error = ValueError("broken")
assert_exceptions_equal(call_record.error, expected_error)
class sfLogger:
def __init__(self, logger_name):
self.format = logging.Formatter("%(message)s")
self.log_queue = queue.Queue()
self.queue_handler = QueueHandler(self.log_queue)
self.queue_handler.setFormatter(self.format)
self.logger = logging.getLogger(logger_name)
self.logger.addHandler(self.queue_handler)
self.logger.setLevel(logging.DEBUG)
self.listener = QueueListener(self.log_queue, self.queue_handler)
self.isStop = False
def start(self):
#print("logger.start()")
self.listener.start()
self.isStop = False
def loggenerator(self):
#print("logger.loggenerator()")
while self.isStop == False:
yield self.log_queue.get().getMessage()
def stop(self):
#print("logger.stop()")
self.listener.stop()
self.isStop = True
while self.log_queue.empty() == False:
self.log_queue.get().getMessage()
def log_worker():
""" Starts a thread in parent process that listens to log queue and writes logs to file on disk"""
h = logging.FileHandler('logs.txt')
pid_log_msg = f'handled by PID {os.getpid()}'
f = logging.Formatter(f'%(name)-15s %(levelname)-8s %(message)s {pid_log_msg}')
h.setFormatter(f)
listener = QueueListener(log_queue, h)
listener.start()
yield
listener.stop()
class AutomatonRunner(object):
def __init__(self, app, interval=1800, buffer_size=20):
self.app = app
self.is_running = False
self.interval = interval
self.logger = logging.getLogger("AutomatonRunner")
self.pool = ThreadPoolExecutor()
self.logging_queue = queue.Queue(-1)
self.logger.addHandler(QueueHandler(self.logging_queue))
pool_scheduler = AsyncIOScheduler()
self.log_source = ReplaySubject(buffer_size=buffer_size,
scheduler=pool_scheduler)
logging_handler = LoggingRxHandler(self.log_source)
logging_handler.setFormatter(
logging.Formatter(
'\033[34m%(asctime)s \033[91m%(name)s\033[0m %(message)s'))
self.logging_queue_listener = QueueListener(self.logging_queue,
logging_handler)
self.logging_queue_listener.start()
def __del__(self):
self.logging_queue_listener.stop()
async def run_forever_in_background(self, delay=0):
try:
await asyncio.sleep(delay)
while True:
if not self.is_running:
fn = functools.partial(self.run)
await self.app.loop.run_in_executor(self.pool, fn)
await asyncio.sleep(self.interval)
except asyncio.CancelledError:
self.logger.info("Runner stopping")
def run_once_no_wait(self):
if not self.is_running:
fn = functools.partial(self.run)
self.logger.info("Start running.")
self.app.loop.run_in_executor(self.pool, fn)
def run(self):
self.is_running = True
automaton = examautomaton.RiskExamAutomaton(
logging_queue=self.logging_queue)
try:
automaton.run()
except Exception as ex:
self.logger.warning(
"Automaton encountered an error: {0}".format(ex))
del automaton
self.is_running = False
class QueueHandler(BaseQueueHandler):
"""
From: https://rob-blackbourn.medium.com/how-to-use-python-logging-queuehandler-with-dictconfig-1e8b1284e27a
"""
def __init__(self,
handlers,
respect_handler_level=False,
auto_run=True,
queue=None):
# noinspection PyTypeChecker
queue = self._resolve_queue(queue or Queue(-1))
super().__init__(queue)
handlers = self._resolve_handlers(handlers)
# noinspection PyUnresolvedReferences
self._listener = QueueListener(
self.queue, *handlers, respect_handler_level=respect_handler_level)
if auto_run:
self.start()
atexit.register(self.stop)
def start(self):
self._listener.start()
def stop(self):
self._listener.stop()
def emit(self, record):
return super().emit(record)
@staticmethod
def _resolve_handlers(h):
if not isinstance(h, ConvertingList):
return h
return [h[i] for i in range(len(h))]
@staticmethod
def _resolve_queue(q):
if not isinstance(q, ConvertingDict):
return q
if '__resolved_value__' in q:
return q['__resolved_value__']
cname = q.pop('class')
klass = q.configurator.resolve(cname)
props = q.pop('.', None) or {}
kwargs = {k: q[k] for k in q if valid_ident(k)}
result = klass(**kwargs)
for name, value in props.items():
setattr(result, name, value)
q['__resolved_value__'] = result
return result
def main():
parser = argparse.ArgumentParser(
description='Listen for documents over 0MQ and validate Resources.')
parser.add_argument(
'proxy_address', type=str,
help="bluesky-0MQ-proxy out address, given as in localhost:5578")
parser.add_argument(
'--emails', required=False, nargs='*',
help="space-separated list of email addresses")
args = parser.parse_args()
log_handler = logging.StreamHandler() # stderr
log_handler.setFormatter(LogFormatter())
logger.setLevel('INFO')
logger.addHandler(log_handler)
if args.emails:
server_name = socket.gethostname()
smtp_handler = SMTPHandler(
mailhost='localhost',
fromaddr=f'Resource Health Check <noreply@{server_name}>',
toaddrs=args.emails,
subject=(f'Error report from resource health check on '
f'{server_name}')
)
smtp_handler.setFormatter(LogFormatter(color=False))
smtp_handler.setLevel('WARNING')
# Use QueueHandler in case sending email is slow. LogRecords flow
# from QueueHandler -> Queue -> QueueListener -> SMTPHandler.
cleanup_listener = True
que = queue.Queue()
queue_handler = QueueHandler(que)
queue_listener = QueueListener(que, smtp_handler,
respect_handler_level=True)
logger.addHandler(queue_handler)
queue_listener.start()
else:
cleanup_listener = False
rr = RunRouter([validator_factory])
rd = RemoteDispatcher(args.proxy_address)
rd.subscribe(rr)
logger.info(f'Listening to {args.proxy_address}')
try:
rd.start() # runs forever
finally:
if cleanup_listener:
queue_listener.stop()
def _run_as_process(func, spider_cls, spider_params, settings):
# Setup logging / progress bar
# (queuehandler --> listener --> root logger --> streamhandler)
progress_bar_enabled = settings['PROGRESS_BAR_ENABLED']
log_enabled = settings['LOG_ENABLED']
logger = None
log_queue = None
log_queue_listener = None
if log_enabled or progress_bar_enabled:
stream_handler = logging.StreamHandler()
if progress_bar_enabled:
stream_handler.terminator = ''
stream_handler.setFormatter(logging.Formatter('%(message)s'))
else:
stream_handler.setFormatter(
logging.Formatter(settings.get('LOG_FORMAT')))
# Contains log messages or progress bar status
log_queue = mp.Queue(-1)
# Forward log messages / progress bar from queue into stream handler
log_queue_listener = QueueListener(log_queue, stream_handler)
log_queue_listener.start()
# Add stream handler to root logger to display real-time results
logger = logging.getLogger()
logger.setLevel(settings.get('LOG_LEVEL'))
logger.addHandler(stream_handler)
# Start function as a separate process
results_queue = mp.Queue()
args = (results_queue, log_queue, spider_cls, spider_params, settings)
process = mp.Process(target=func, args=args)
process.start()
result = results_queue.get()
process.join()
process.terminate()
if log_queue_listener is not None:
log_queue_listener.stop()
if logger is not None:
logger.removeHandler(stream_handler)
if isinstance(result, BaseException):
raise result
class IfStateLogging:
STYLE_OK = "ok"
STYLE_CHG = "chg"
STYLE_DEL = "del"
ANSI_GREEN = "\033[32m"
ANSI_RED = "\033[31m"
ANSI_MAGENTA = "\033[35m"
ANSI_YELLOW = "\033[33m"
ANSI_RESET = "\033[0m"
ANSI_BOLD = "\033[1m"
@staticmethod
def colorize(style):
if style == IfStateLogging.STYLE_OK:
return IfStateLogging.ANSI_GREEN
if style == IfStateLogging.STYLE_CHG:
return IfStateLogging.ANSI_YELLOW
if style == IfStateLogging.STYLE_DEL:
return IfStateLogging.ANSI_YELLOW
return ""
def __init__(self, level, handlers=[]):
if level != logging.DEBUG:
sys.tracebacklimit = 0
logging.basicConfig(
level=level,
format='%(bol)s%(prefix)s%(style)s%(message)s%(eol)s',
)
f = IfStateLogFilter(sys.stderr.isatty())
logger.addFilter(f)
qu = queue.SimpleQueue()
logger.addHandler(QueueHandler(qu))
self.listener = QueueListener(qu,
*handlers,
respect_handler_level=True)
self.listener.start()
def quit(self):
self.listener.stop()
class AsyncWrapperHandler(QueueHandlerAsyncHandler):
"""Wrapper of the asynchronous queue handler class."""
def __init__(self, handler, *args, **kwargs):
"""The queue and its listener are initialized."
Args:
handler (class): Handler for the logging queue.
"""
self.queue = queue.Queue(MAX_QUEUE_SIZE)
super().__init__(self.queue)
self.handler = handler(*args, **kwargs)
self.handler_name = self.handler.__class__.__name__
self.listener = QueueListener(self.queue, self.handler)
self.counter_overflow_queue = Counter(
f"counter_overflow_queue_{self.handler_name}", "messages")
self.listener.start()
def __del__(self):
"""Stop the queue listener."""
self.listener.stop()
def test_before_and_after_node_run_hooks_parallel_runner(
self, tmp_path, logging_hooks, dummy_dataframe
):
log_records = []
session = KedroSession.create(MOCK_PACKAGE_NAME, tmp_path)
context = session.load_context()
catalog = context.catalog
catalog.save("cars", dummy_dataframe)
catalog.save("boats", dummy_dataframe)
class LogHandler(logging.Handler): # pylint: disable=abstract-method
def handle(self, record):
log_records.append(record)
logs_queue_listener = QueueListener(logging_hooks.queue, LogHandler())
logs_queue_listener.start()
try:
session.run(runner=ParallelRunner(), node_names=["node1", "node2"])
finally:
logs_queue_listener.stop()
before_node_run_log_records = [
r for r in log_records if r.funcName == "before_node_run"
]
assert len(before_node_run_log_records) == 2
for record in before_node_run_log_records:
assert record.getMessage() == "About to run node"
assert record.node.name in ["node1", "node2"]
assert set(record.inputs.keys()) <= {"cars", "boats"}
after_node_run_log_records = [
r for r in log_records if r.funcName == "after_node_run"
]
assert len(after_node_run_log_records) == 2
for record in after_node_run_log_records:
assert record.getMessage() == "Ran node"
assert record.node.name in ["node1", "node2"]
assert set(record.outputs.keys()) <= {"planes", "ships"}
class QueueListenerHandler(QueueHandler):
def __init__(
self, handlers, respect_handler_level=True, auto_run=True
):
queue=Queue(-1) # Infinite Queue
super().__init__(queue)
handlers = _resolve_handlers(handlers)
self._listener = QueueListener(
self.queue, *handlers, respect_handler_level=respect_handler_level
)
if auto_run:
self.start()
register(self.stop)
def start(self):
self._listener.start()
def stop(self):
self._listener.stop()
def emit(self, record):
return super().emit(record)
class Logger:
def __init__(self, logger_name, logs_folder):
self.logs_folder = logs_folder
self.logger = logging.getLogger(logger_name)
self.logger.setLevel('DEBUG')
handlers = list()
logging.raiseExceptions = True
if not os.path.exists(self.logs_folder):
os.mkdir(self.logs_folder)
data_handler = logging.FileHandler(os.path.join(self.logs_folder, f'{logger_name}.log'))
data_handler.setFormatter(MetricFormatter())
handlers.append(data_handler)
# организуем неблокирующие записи логов
logs_queue = Queue(-1)
queue_handler = QueueHandler(logs_queue)
self.listener = QueueListener(logs_queue, *handlers)
self.logger.addHandler(queue_handler)
self.listener.start()
def __del__(self):
self.listener.stop()
def debug(self, message, extra=None):
self.logger.debug(message, extra=extra)
def info(self, message, extra=None):
self.logger.info(message, extra=extra)
def warning(self, message, extra=None):
self.logger.warning(message, extra=extra)
def error(self, message, extra=None):
self.logger.error(message, extra=extra)
@staticmethod
def get_logger(name):
return logging.getLogger(name)
def test_before_and_after_dataset_loaded_hooks_parallel_runner(
self, tmp_path, logging_hooks, dummy_dataframe
):
log_records = []
session = KedroSession.create(MOCK_PACKAGE_NAME, tmp_path)
context = session.load_context()
catalog = context.catalog
catalog.save("cars", dummy_dataframe)
catalog.save("boats", dummy_dataframe)
class LogHandler(logging.Handler): # pylint: disable=abstract-method
def handle(self, record):
log_records.append(record)
logs_queue_listener = QueueListener(logging_hooks.queue, LogHandler())
logs_queue_listener.start()
try:
session.run(runner=ParallelRunner(), node_names=["node1", "node2"])
finally:
logs_queue_listener.stop()
before_dataset_loaded_log_records = [
r for r in log_records if r.funcName == "before_dataset_loaded"
]
assert len(before_dataset_loaded_log_records) == 2
for record in before_dataset_loaded_log_records:
assert record.getMessage() == "Before dataset loaded"
assert record.dataset_name in ["cars", "boats"]
after_dataset_loaded_log_records = [
r for r in log_records if r.funcName == "after_dataset_loaded"
]
assert len(after_dataset_loaded_log_records) == 2
for record in after_dataset_loaded_log_records:
assert record.getMessage() == "After dataset loaded"
assert record.dataset_name in ["cars", "boats"]
pd.testing.assert_frame_equal(record.data, dummy_dataframe)
def main():
que = queue.Queue(-1) # no limit on size
queue_handler = QueueHandler(que)
logger.addHandler(queue_handler)
#設定這個log 分身他要處理的情報等級
logger.setLevel(logging.WARNING)
#關於 log 將要輸出的檔案，請你按照下面的設定，幫我處理一下
fh = logging.FileHandler('Test.log', 'a', 'utf-8')
#設定這個檔案要處理的情報等級，只要是 INFO 等級或以上的就寫入檔案
fh.setLevel(logging.INFO)
# create console handler with a higher log level
#關於 console(也就是cmd 那個黑黑的畫面)，請你按照下面的設定，幫我處理一下
ch = logging.StreamHandler()
#設定 Console 要處理的情報等級，只要是 DEBUG 等級的就印出來
ch.setLevel(logging.DEBUG)
# create formatter and add it to the handlers
# log 印出來的格式
formatter = logging.Formatter(
'%(asctime)s %(module)10s. line:%(lineno)3d - %(levelname)5s - Thread: %(thread)d\n\t%(message)s\n'
)
#將 印出來的格式和 File Handle, Console Handle 物件組合在一起
fh.setFormatter(formatter)
ch.setFormatter(formatter)
#加上這個!!!!!每天深夜換檔案，receive.log 當然可以使用日期當作檔名，就自己去玩拉！
#logHandler = TimedRotatingFileHandler("receive.log",when="midnight")
# add the handlers to the logger
#log 的分身組合 File Handle 和 Console Handle
#logger.addHandler(fh)
logger.addHandler(ch)
#logger.addHandler(logHandler) #加上這個!!!!!
listener = QueueListener(que, fh)
listener.start()
some_method()
listener.stop()
def child_process_logging(boot_info: BootInfo) -> Iterator[None]:
# We get the root logger here to ensure that all logs are given a chance to
# pass through this handler
logger = logging.getLogger()
logger.setLevel(boot_info.min_log_level)
set_logger_levels(boot_info.logger_levels)
ipc_handler = IPCHandler.connect(boot_info.trinity_config.logging_ipc_path)
ipc_handler.setLevel(boot_info.min_log_level)
# Push all logs into a queue, because sometimes pushing into the socket is
# slow and we don't want to block the event loop. Inspired by:
# https://docs.python.org/3.8/howto/logging-cookbook.html#dealing-with-handlers-that-block
log_queue: Queue[str] = Queue(-1)
queue_handler = QueueHandler(log_queue)
queue_listener = QueueListener(
log_queue,
ipc_handler,
respect_handler_level=True,
)
logger.addHandler(queue_handler)
logger.debug(
'Logging initialized for file %s: PID=%s',
boot_info.trinity_config.logging_ipc_path.resolve(),
os.getpid(),
)
with ipc_handler:
queue_listener.start()
try:
yield
finally:
logger.removeHandler(queue_handler)
queue_listener.stop()
def logging_on(log_queue, config=None):
"""Activate queued logging.
This context activates logging through the use of logging's QueueHandler and
QueueListener.
Whether the default config parameters are used or a custom configuration is
passed, the log handlers are passed to a QueueListener instance, such that
the subprocesses of trollflow2 can use a QueueHandler to communicate logs.
"""
root = logging.getLogger()
# Lift out the existing handlers (we need to keep these for pytest's caplog)
handlers = root.handlers.copy()
if config is None:
config = DEFAULT_LOG_CONFIG
logging.config.dictConfig(config)
# set up and run listener
listener = QueueListener(log_queue, *(root.handlers + handlers))
listener.start()
try:
yield
finally:
listener.stop()
def run(self, p_processors_nb_threads, p_writer_nb_threads=None):
# All log messages come and go by this queue
log_queue = Queue()
logger = logging.getLogger('swallow')
if len(logger.handlers) > 1:
logger.warn(
"Several handlers detected on swallow logger but can't log to more than a single handler in multiprocessing mode. Only the first one will be used."
)
elif len(logger.handlers) == 0:
logger.warn(
"No handler defined for swallow logger. Log to console with info level."
)
# Handler console
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.INFO)
logger.addHandler(stream_handler)
# each log_listener gets records from the queue and sends them to a specific handler
handler = logger.handlers[0]
formatter = handler.formatter
listener = QueueListener(log_queue, handler)
listener.start()
if p_writer_nb_threads is None:
p_writer_nb_threads = p_processors_nb_threads
logger.info(
'Running swallow process. Processor on %i threads / Writers on %i threads',
p_processors_nb_threads, p_writer_nb_threads)
start_time = datetime.datetime.now()
# Set extra properties to readers
for reader in self.readers:
reader['reader'].counters = self.counters
reader['reader'].log_queue = log_queue
reader['reader'].log_level = logger.level
reader['reader'].formatter = formatter
# Set extra properties to writer
if self.writer is not None:
self.writer.counters = self.counters
self.writer.log_queue = log_queue
self.writer.log_level = logger.level
self.writer.formatter = formatter
read_worker = [
Process(target=reader['reader'].scan_and_queue,
args=(self.in_queue, ),
kwargs=(reader['args'])) for reader in self.readers
]
process_worker = [
Process(target=get_and_parse,
args=(self.in_queue, self.out_queue, self.process,
self.counters, log_queue, logger.level, formatter),
kwargs=(self.process_args))
for i in range(p_processors_nb_threads)
]
# writers are optionnal
if self.writer is not None:
write_worker = [
Process(target=self.writer.dequeue_and_store,
args=(self.out_queue, ),
kwargs=(self.writer_store_args))
for i in range(p_writer_nb_threads)
]
else:
write_worker = []
# Running workers
for work in read_worker:
work.start()
for work in process_worker:
work.start()
for work in write_worker:
work.start()
# Waiting for workers to end :
# worker.join() blocks the programm till the worker ends
logger.info('Waiting for reader to finish')
for work in read_worker:
# Waiting for all reader to finish their jobs
work.join()
# At this point, reading is finished. We had a poison pill for each consumer of read queue :
for i in range(len(process_worker)):
self.in_queue.put(None)
logger.info('Waiting for processors to finish')
for work in process_worker:
# Waiting for all processors to finish their jobs
work.join()
# At this point, processing is finished. We had a poison pill for each consumer of write queue :
for i in range(len(write_worker)):
self.out_queue.put(None)
logger.info('Waiting for writers to finish')
for work in write_worker:
# Waiting for all writers to finish their jobs
work.join()
elsapsed_time = datetime.datetime.now() - start_time
logger.info('Elapsed time : %ss' % elsapsed_time.total_seconds())
avg_time = 0
nb_items = self.counters['nb_items_scanned'].value
if nb_items:
avg_time = 1000 * self.counters['scan_time'].value / nb_items
logger.info('{0} items scanned ({1}ms)'.format(nb_items, avg_time))
avg_time = 0
avg_time_idle = 0
nb_items = self.counters['nb_items_processed'].value
if nb_items:
avg_time = 1000 * self.counters[
'real_process_time'].value / nb_items
avg_time_idle = 1000 * self.counters[
'idle_process_time'].value / nb_items
logger.info(
'{0} items processed (process : {1}ms / idle : {2}ms)'.format(
nb_items, avg_time, avg_time_idle))
avg_time = 0
nb_items = self.counters['nb_items_stored'].value
if nb_items:
avg_time = 1000 * self.counters[
'whole_storage_time'].value / nb_items
logger.info('{0} items stored ({1}ms)'.format(nb_items, avg_time))
nb_items = self.counters['nb_items_error'].value
logger.info('{0} items error'.format(nb_items))
# Stop listening for log messages
listener.stop()
class Logger:
"""
用于记录抓取过程
"""
class CounterHandler(logging.NullHandler):
def __init__(self, save_result=True):
super().__init__()
self.__counter = defaultdict(int)
self.__result = defaultdict(list)
self.__save_result = save_result
def handle(self, record):
self.__counter[record.levelname] += 1
if self.__save_result:
self.__result[record.levelname].append(record.message)
def report(self):
t = [self.__counter[i] for i in self.__counter]
t = sum(t)
s = [f'记录{i}有:{self.__counter[i]} 个' for i in self.__counter]
s = '\n'.join(s)
s = f'共有:{t} 个记录,其中\n' + s
return s
def result(self):
if self.__save_result:
return self.__result
def __init__(self, debug=False):
"""
当debug为True时，不记录到日志文件，只输出到控制台
"""
self.debug = debug
self.__q = Queue()
self.__counter = None
self.__file_handler = TimedRotatingFileHandler('crawler.log',
when='D',
interval=3,
encoding='utf-8')
self.__stdout = logging.StreamHandler(sys.stdout)
self.__qh = QueueHandler(self.__q)
self.__logger = logging.getLogger('logger.Logger')
self.__logger.setLevel(20)
self.__listener = None
self.__time = None
def start(self, save_result=True):
self.__logger.addHandler(self.__qh)
self.__counter = self.CounterHandler(save_result)
if self.debug:
self.__logger.addHandler(self.__stdout)
self.__listener = QueueListener(self.__q, self.__counter)
else:
self.__listener = QueueListener(self.__q, self.__counter,
self.__file_handler)
self.__listener.start()
self.__time = time.time()
def stop(self):
self.__time = time.time() - self.__time
self.__listener.stop()
self.__logger.handlers = []
self.__listener.handlers = []
def info(self, msg, *args, **kwargs):
self.__logger.info(msg, *args, **kwargs)
def warning(self, msg, *args, **kwargs):
self.__logger.warning(msg, *args, **kwargs)
def error(self, msg, *args, **kwargs):
self.__logger.error(msg, *args, **kwargs)
def report(self):
return f'运行时间：{self.__time}.\n{self.__counter.report()}'
def result(self):
return self.__counter.result()
class Parse():
'''
This is the main parsing class that takes input data
in the form of text files, parses them into dictionary
and list attributes and provides methods for performing
operations: Gaussian fits, F-N calculations, Rectification,
Vtrans, and dJ/DV.
'''
from gaussfit.parse.libparse import findtraces
from gaussfit.parse.libparse import dodjdv
from gaussfit.parse.libparse import findmin
from gaussfit.parse.libparse import dorect
# Class variables
error = False
parsed = False
df = pd.DataFrame()
avg = pd.DataFrame()
XY = OrderedDict()
X = np.array([])
FN = {}
compliance_traces = []
ohmic = []
DJDV = {}
GHists = OrderedDict()
NDC = []
NDCHists = OrderedDict()
filtered = []
R = {}
segments = {}
segments_nofirst = {}
logger = logging.getLogger(__package__)
logqueue = Queue(-1)
def __init__(self, opts, handler=None):
self.opts = opts
# Pass your own log handler, e.g., when calling from a GUI
# But make sure it supports flush(), setDelay() and unsetDelay() methods!
if not handler:
self.loghandler = DelayedHandler()
self.loghandler.setFormatter(logging.Formatter(
fmt=GREEN+os.path.basename(
'%(name)s'+TEAL)+' %(levelname)s '+YELLOW+'%(message)s'+WHITE))
else:
self.loghandler = handler
self.logger.addHandler(self.loghandler)
self.logger.setLevel(getattr(logging, self.opts.loglevel.upper()))
self.loglistener = QueueListener(self.logqueue, self.loghandler)
self.loglistener.start()
if not 0 < self.opts.alpha < 1:
self.logger.error("Alpha must be between 0 and 1")
sys.exit()
def readfiles(self, fns, parse=True):
'''Walk through input files and parse
them into attributes '''
frames = {}
fns.sort()
if isinstance(fns, str):
fns = [fns]
self.logger.debug('Parsing %s', ', '.join(fns))
if self.opts.ycol > -1:
self.logger.info("Parsing two columns of data (X=%s, Y=%s).", self.opts.xcol+1, self.opts.ycol+1)
for f in fns:
with open(f, 'rt') as fh:
_headers = fh.readline().split(self.opts.delim)
try:
if _headers:
_x, _y = _headers[self.opts.xcol].strip(), _headers[self.opts.ycol].strip()
frames[f] = pd.read_csv(f, sep=self.opts.delim,
usecols=(_x, _y))[[_x, _y]]
frames[f].rename(columns={_x: 'V', _y: 'J'}, inplace=True)
# self.logger.debug("Renaming headers %s -> V, %s -> J" % (_x, _y))
elif self.opts.X > self.opts.Y:
raise pd.errors.ParserError("xcol cannot be greater than ycol without column headers.")
else:
# self.logger.debug("No headers, manually setting V/J")
frames[f] = pd.read_csv(f, sep=self.opts.delim,
usecols=(self.opts.xcol,
self.opts.ycol),
names=('V', 'J'), header=0)
except OSError as msg:
self.logger.warning("Skipping %s because %s", f, str(msg))
except pd.errors.ParserError as msg:
self.logger.warning("Skipping malformatted %s because %s", f, str(msg))
else:
self.logger.info("Parsing all columns of data.")
for f in fns:
try:
_df = pd.read_csv(f, sep=self.opts.delim,
index_col=self.opts.xcol,
header=0,
error_bad_lines=False,
warn_bad_lines=False)
i = 0
for col in _df:
frames['%s_%.2d' % (f, i)] = pd.DataFrame({'V': _df.index, 'J': _df[col]})
# self.logger.debug("Adding frame %s_%.2d" % (f,i) )
i += 1
except OSError as msg:
self.logger.warning("Skipping %s because %s", f, str(msg))
# self.df = pd.concat((pd.read_csv(f,sep=self.opts.delim,
# header=None,skiprows=1) for f in fns),ignore_index=True)
# X,Y = [],[]
# for row in self.df.iterrows():
# for y in row[1][1:]:
# X.append(row[1][0])
# Y.append(y)
# self.df = pd.DataFrame({'V':X,'J':Y})
if not frames:
self.logger.error("No files to parse!")
sys.exit()
# Create main dataframe and parse it
self.df = pd.concat(frames)
# print(self.df)
self.__parse(parse)
def readpandas(self, df, parse):
'''Take a pandas.DataFrame as input instead of files.'''
self.logger.debug("Using Pandas as input")
self.df = df
self.__parse(parse)
def __parse(self, parse):
'''Read a pandas.DataFrame and compute Fowler-Nordheim
values, log10 the J or I values and create a dictionary
indexed by unique voltages.'''
if (self.df.V.dtype, self.df.J.dtype) != ('float64', 'float64'):
self.logger.error("Parsed data does not appear to contain numerical data!")
self.error = True
return
if self.df.J.first_valid_index() is None:
self.logger.error("Column %s is empty!", str(self.opts.ycol+1))
self.error = True
return
if self.df.J.hasnans:
self.logger.warning("Input contains non-numerical data!")
try:
self.df['FN'] = np.log(abs(self.df.J)/self.df.V**2)
except ZeroDivisionError:
self.logger.warning("Error computing FN (check your input data).")
self.df['FN'] = np.array([x*0 for x in range(0, len(self.df['V']))])
self.df.J.replace(0.0, value=1e-16, inplace=True)
self.df['logJ'] = np.log10(abs(self.df.J)) # Cannot log10 zero
self.logger.info('%s values of log|J| above compliance (%s)',
len(self.df['logJ'][self.df['logJ'] > self.opts.compliance]), self.opts.compliance)
# The default log handler only emits when you call flush() after setDelay() called
self.loghandler.setDelay()
# In the event that we want to call parsing method by hand
# we stop here when just self.df is complete
if parse:
self.__parsedataset()
def __parsedataset(self):
children = []
xy = []
for x, group in self.df.groupby('V'):
xy.append((x, group))
self.logger.info("* * * * * * Finding segments * * * * * * * *")
conn = gettmpfilename()
children.append([conn, findSegments(conn, self.logqueue, self.df)])
children[-1][1].start()
self.logger.info("* * * * * * Finding traces * * * * * * * *")
self.loghandler.flush()
self.findtraces()
self.logger.info("* * * * * * Computing Lag * * * * * * * * *")
conn = gettmpfilename()
children.append([conn, doLag(conn, self.logqueue, xy)])
children[-1][1].start()
self.dodjdv()
self.findmin()
R = self.dorect(xy)
children[1][1].join()
with open(children[1][0], 'r+b') as fh:
lag = pickle.load(fh)
os.unlink(children[1][0])
self.logger.info("* * * * * * Computing Gaussians * * * * * * * * *")
self.loghandler.flush()
for x, group in xy:
self.XY[x] = {
"Y": group['J'],
"LogY": group['logJ'],
"hist": dohistogram(self.logqueue, group['logJ'], label="J", warnings=True),
"Y_nofirst": [0],
"LogY_nofirst": [0],
"hist_nofirst": dohistogram(self.logqueue, np.array([0]), label="J"),
"filtered_hist": dohistogram(self.logqueue, lag[x]['filtered'], label="lag"),
"lag": lag[x]['lagplot'],
"FN": group['FN'],
"R": R[x]}
if self.opts.heatmapd == 0:
self.GHists = OrderedDict()
for x in self.XY:
self.GHists[x] = {}
self.GHists[x]['hist'] = self.XY[x]['hist']
children[0][1].join()
with open(children[0][0], 'r+b') as fh:
self.error, self.segments, self.segmenthists_nofirst, nofirsttrace = pickle.load(fh)
os.unlink(children[0][0])
if nofirsttrace:
for x, group in xy:
self.XY[x]["Y_nofirst"] = nofirsttrace[x]
self.XY[x]["LogY_nofirst"] = [np.log10(abs(_x)) for _x in nofirsttrace[x]]
self.XY[x]["hist_nofirst"] = dohistogram(self.logqueue, nofirsttrace[x], label="J")
self.logger.info("* * * * * * Computing |V^2/J| * * * * * * * * *")
self.loghandler.flush()
for x in self.XY:
self.XY[x]['VT'] = abs(x**2 / 10**self.XY[x]['hist']['mean'])
self.logger.info("* * * * * * * * * * * * * * * * * * * * * * ")
self.loghandler.flush()
if not self.error:
printFN(self.logger, self.FN)
self.loghandler.unsetDelay()
try:
self.loglistener.stop()
except EOFError:
pass
if self.error:
self.logger.error('Cannot compute statistics from these traces. (Did you set segments correctly?)')
self.loghandler.flush()
return # Bail if we can't parse traces
self.parsed = True
def wait(self):
'''
Wait at most 60 seconds for either an error to occur or
for the parser to complete.
'''
self.logger.debug("Waiting for parser to complete.")
t = 0
while not self.parsed and not self.error:
if t > 60:
self.logger.error("Timeout waiting for parser to complete.")
sys.exit(-1)
break
time.sleep(1)
t += 1
if self.error:
self.logger.error("!!! Parser completing with error, check the results carefully !!!")
self.loghandler.flush()
def getXY(self):
'''Public method to return the main XY dictionary'''
self.wait()
if self.error:
return {}
else:
return self.XY
def getFN(self):
'''Public method to reutrn the main FN dictionary'''
self.wait()
if self.error:
return {}
else:
return self.FN
def main(argv=None):
parser = argparse.ArgumentParser(
description="Tool for managing server hardware via the Redfish API."
)
parser.add_argument("-H", help="iDRAC host address")
parser.add_argument("-u", help="iDRAC username", required=True)
parser.add_argument("-p", help="iDRAC password", required=True)
parser.add_argument("-i", help="Path to iDRAC interfaces yaml", default=None)
parser.add_argument("-t", help="Type of host. Accepts: foreman, director")
parser.add_argument(
"-l", "--log", help="Optional argument for logging results to a file"
)
parser.add_argument(
"-f",
"--force",
dest="force",
action="store_true",
help="Optional argument for forced clear-jobs",
)
parser.add_argument(
"--host-list",
help="Path to a plain text file with a list of hosts.",
default=None,
)
parser.add_argument(
"--pxe", help="Set next boot to one-shot boot PXE", action="store_true"
)
parser.add_argument(
"--boot-to", help="Set next boot to one-shot boot to a specific device"
)
parser.add_argument(
"--boot-to-type",
help="Set next boot to one-shot boot to either director or foreman",
)
parser.add_argument(
"--boot-to-mac",
help="Set next boot to one-shot boot to a specific MAC address on the target",
)
parser.add_argument(
"--reboot-only", help="Flag for only rebooting the host", action="store_true"
)
parser.add_argument(
"--power-cycle",
help="Flag for sending ForceOff instruction to the host",
action="store_true",
)
parser.add_argument(
"--power-state", help="Get power state", action="store_true",
)
parser.add_argument(
"--power-on", help="Power on host", action="store_true",
)
parser.add_argument(
"--power-off", help="Power off host", action="store_true",
)
parser.add_argument("--racreset", help="Flag for iDRAC reset", action="store_true")
parser.add_argument(
"--factory-reset",
help="Reset BIOS to default factory settings",
action="store_true",
)
parser.add_argument(
"--check-boot",
help="Flag for checking the host boot order",
action="store_true",
)
parser.add_argument(
"--firmware-inventory", help="Get firmware inventory", action="store_true"
)
parser.add_argument(
"--clear-jobs",
help="Clear any scheduled jobs from the queue",
action="store_true",
)
parser.add_argument(
"--ls-jobs", help="List any scheduled jobs in queue", action="store_true",
)
parser.add_argument("-v", "--verbose", help="Verbose output", action="store_true")
parser.add_argument(
"-r",
"--retries",
help="Number of retries for executing actions.",
default=RETRIES,
)
_args = vars(parser.parse_args(argv))
log_level = DEBUG if _args["verbose"] else INFO
host_list = _args["host_list"]
host = _args["H"]
result = True
if host_list:
FMT = "[%(name)s] - %(levelname)-8s - %(message)s"
FILEFMT = "%(asctime)-12s: [%(name)s] - %(levelname)-8s - %(message)s"
else:
FMT = "- %(levelname)-8s - %(message)s"
FILEFMT = "%(asctime)-12s: %(levelname)-8s - %(message)s"
_queue = Queue()
_stream_handler = StreamHandler()
_stream_handler.setFormatter(Formatter(FMT))
_queue_listener = QueueListener(_queue, _stream_handler)
_logger = getLogger(__name__)
_queue_handler = QueueHandler(_queue)
_logger.addHandler(_queue_handler)
_logger.setLevel(log_level)
_queue_listener.start()
if _args["log"]:
file_handler = FileHandler(_args["log"])
file_handler.setFormatter(Formatter(FILEFMT))
file_handler.setLevel(log_level)
_queue_listener.handlers = _queue_listener.handlers + (file_handler,)
loop = asyncio.get_event_loop()
tasks = []
if host_list:
try:
with open(host_list, "r") as _file:
for _host in _file.readlines():
logger = getLogger(_host.split(".")[0])
logger.addHandler(_queue_handler)
logger.setLevel(log_level)
fn = functools.partial(
execute_badfish, _host.strip(), _args, logger
)
tasks.append(fn)
except IOError as ex:
_logger.debug(ex)
_logger.error("There was something wrong reading from %s" % host_list)
results = []
try:
results = loop.run_until_complete(
asyncio.gather(*[task() for task in tasks], return_exceptions=True)
)
except KeyboardInterrupt:
_logger.warning("\nBadfish terminated.")
result = False
except (asyncio.CancelledError, BadfishException) as ex:
_logger.warning("There was something wrong executing Badfish.")
_logger.debug(ex)
result = False
if results:
result = True
_logger.info("RESULTS:")
for res in results:
if len(res) > 1 and res[1]:
_logger.info(f"{res[0]}: SUCCESSFUL")
else:
_logger.info(f"{res[0]}: FAILED")
result = False
elif not host:
_logger.error(
"You must specify at least either a host (-H) or a host list (--host-list)."
)
else:
try:
_host, result = loop.run_until_complete(
execute_badfish(host, _args, _logger)
)
except KeyboardInterrupt:
_logger.warning("Badfish terminated.")
except BadfishException as ex:
_logger.warning("There was something wrong executing Badfish.")
_logger.debug(ex)
result = False
_queue_listener.stop()
if result:
return 0
return 1
class TelegramHandler(QueueHandler):
"""
Handler that takes telegram params.
Instantiate queue and start listener.
"""
# Message for setting unexpected class as formatter
FORMATTER_WARNING = 'Formatter class is not subclass of telegram_logger.TelegramFormatter, \
its possible problems with sending long log message to telegram'
def __init__(self, chat_ids: List[str], token: str, proxies: Optional[Dict[str, str]]=None,
disable_web_page_preview: bool=False, disable_notification: bool=False,
reply_to_message_id: Optional[int]=None,
reply_markup: Optional[Dict[str, Any]]=None) -> None:
"""
Initialization.
:param token: Telegram token.
:optional proxies: Proxy for requests. Format proxies corresponds format proxies
in requests library.
Parameters for message to telegram, see https://core.telegram.org/bots/api#sendmessage
:optional disable_web_page_preview: Disables link previews for links in this message.
:optional disable_notification: Sends the message silently.
Users will receive a notification with no sound.
:optional reply_to_message_id: If the message is a reply, ID of the original message.
:optional reply_markup: Additional interface options.
A JSON-serialized object for an inline keyboard, custom reply keyboard,
instructions to remove reply keyboard or to force a reply from the user.
"""
self.queue = Queue(-1) # type: Queue
super().__init__(self.queue)
self.handler = TelegramMessageHandler(
chat_ids,
token,
proxies=proxies,
disable_web_page_preview=disable_web_page_preview,
disable_notification=disable_notification,
reply_to_message_id=reply_to_message_id,
reply_markup=reply_markup
)
# Set default formatter
self.handler.setFormatter(TelegramHtmlFormatter())
self.listener = QueueListener(self.queue, self.handler)
self.listener.start()
def setFormatter(self, formatter: logging.Formatter) -> None:
"""
Set formatter to handler.
:param formatter: Formatter instance.
"""
if not isinstance(formatter, TelegramFormatter):
logger.warning(self.FORMATTER_WARNING)
self.handler.setFormatter(formatter)
def prepare(self, record: logging.LogRecord) -> logging.LogRecord:
"""
Prepare record.
"""
return record
def close(self) -> None:
"""
Wait till all records will be processed then stop listener.
"""
self.listener.stop()
super().close()
class JobLoggingManager:
"""
Manages logging for a Vesper job.
A `JobLoggingManager` manages logging for the processes of a Vesper job.
Log records can be submitted by any process of a job using any logger
(typically the root logger) configured with the `configure_logger`
static method. A logger so configured writes each log record to a
multiprocessing queue that is read by a thread running in the main
job process, which in turn writes log messages to the job's log file.
"""
@staticmethod
def configure_logger(logger, logging_config):
"""
Configures the specified logger to write log records to this job's
logging queue.
For the `logging_config` argument, the main job process can pass
the `logging_config` attribute of its `JobLoggingManager`. This
information is also passed to the `execute` method of the job's
command as the `logging_config` attribute of the command's
execution context. The information is picklable, so it can be
delivered easily to any additional process started by the main
job process as an argument to the process's target function.
"""
level, queue = logging_config
logger.setLevel(level)
handler = QueueHandler(queue)
logger.addHandler(handler)
def __init__(self, job, level):
self.job = job
self.level = level
# Create queue through which log records can be sent from various
# processes and threads to the logging thread.
self.queue = Queue()
formatter = Formatter('%(asctime)s %(levelname)-8s %(message)s')
# Create handler that writes log messages to the job log file.
os_utils.create_parent_directory(job.log_file_path)
file_handler = FileHandler(job.log_file_path, 'w')
file_handler.setFormatter(formatter)
# Create handler that writes log messages to stderr.
stderr_handler = StreamHandler()
stderr_handler.setFormatter(formatter)
self._record_counts_handler = _RecordCountsHandler()
# Create logging listener that will run on its own thread and log
# messages sent to it via the queue.
self._listener = QueueListener(
self.queue, file_handler, stderr_handler,
self._record_counts_handler)
@property
def logging_config(self):
return (self.level, self.queue)
@property
def record_counts(self):
return dict(self._record_counts_handler.record_counts)
def start_up_logging(self):
self._listener.start()
def shut_down_logging(self):
# Tell logging listener to terminate, and wait for it to do so.
self._listener.stop()
logging.shutdown()
# Blocking Handlers
import queue
import logging
from logging.handlers import QueueHandler, QueueListener
que = queue.Queue(-1)
queue_handler = QueueHandler(que)
handler = logging.StreamHandler()
listener = QueueListener(que, handler)
root = logging.getLogger()
root.addHandler(queue_handler)
formatter = logging.Formatter("%(threadName)s: %(message)s")
handler.setFormatter(formatter)
listener.start()
root.warning("Look Out")
listener.stop()
def main() -> None:
config_fp = pathlib.Path(sys.argv[0]).parent / "config.json"
with config_fp.open("r") as fh:
config = json.load(fh)
engine = sa.create_engine(config["db_uri"])
letl.db.create_tables(engine=engine, recreate=True)
jobs = [
letl.Job(
job_name=f"Job4",
timeout_seconds=20,
dependencies=frozenset({"Job1"}),
retries=1,
run=job4,
config=Config("job4_payload"),
schedule=frozenset({letl.Schedule.every_x_seconds(seconds=30)}),
),
letl.Job(
job_name=f"Job1",
timeout_seconds=20,
dependencies=frozenset(),
retries=1,
run=job1,
config=Config("job1_payload"),
schedule=frozenset({letl.Schedule.every_x_seconds(seconds=30)}),
),
letl.Job(
job_name=f"Job2",
timeout_seconds=5,
dependencies=frozenset(),
retries=1,
run=job2,
config=Config("job2_payload"),
schedule=frozenset({letl.Schedule.every_x_seconds(seconds=30)}),
),
letl.Job(
job_name=f"Job3",
timeout_seconds=20,
dependencies=frozenset(),
retries=1,
run=job3,
config=Config("job3_payload"),
schedule=frozenset({letl.Schedule.every_x_seconds(seconds=30)}),
),
]
formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")
file_handler = RotatingFileHandler("error.log", maxBytes=2000, backupCount=0)
file_handler.setFormatter(formatter)
file_handler.setLevel(logging.ERROR)
console_handler = logging.StreamHandler()
console_handler.setFormatter(formatter)
console_handler.setLevel(logging.INFO)
log_queue = mp.Queue(-1) # type: ignore
queue_handler = QueueHandler(log_queue)
log_listener = QueueListener(log_queue, console_handler, file_handler)
letl.root_logger.setLevel(logging.INFO)
letl.root_logger.addHandler(queue_handler)
log_listener.start()
try:
letl.start(
jobs=jobs,
etl_db_uri=config["db_uri"],
max_job_runners=3,
log_sql_to_console=False,
log_level=letl.LogLevel.Debug,
)
finally:
log_listener.stop()
thread_manager.start()
except Exception as error:
sys.exit('Failed to start Thread Mananger. Error: {}'.format(error))
# start State manager
try:
state_manager = State_manager()
state_manager.start()
except Exception as error:
sys.exit('Failed to start State Mananger. Error: {}'.format(error))
main_logger.info('All processes started successfully')
listener.start()
while True:
Loggers.update_handlers(listener)
if not queue.empty():
status, message = queue.get()
if status:
#logging.info(colored('{}'.format(message), 'green'))
#logger.info(message)
main_logger.info(colored('{}'.format(message), 'green'))
else:
#logging.info(colored('{}'.format(message), 'red'))
#logger.info(message)
main_logger.info(colored('{}'.format(message), 'red'))
time.sleep(2)
listener.stop()
def run(self, p_processors_nb_threads, p_writer_nb_threads=None):
# All log messages come and go by this queue
log_queue = Queue()
logger = logging.getLogger('swallow')
if len(logger.handlers) > 1:
logger.warn("Several handlers detected on swallow logger but can't log to more than a single handler in multiprocessing mode. Only the first one will be used.")
elif len(logger.handlers) == 0:
logger.warn("No handler defined for swallow logger. Log to console with info level.")
# Handler console
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.INFO)
logger.addHandler(stream_handler)
# each log_listener gets records from the queue and sends them to a specific handler
handler = logger.handlers[0]
formatter = handler.formatter
listener = QueueListener(log_queue, handler)
listener.start()
if p_writer_nb_threads is None:
p_writer_nb_threads = p_processors_nb_threads
logger.info('Running swallow process. Processor on %i threads / Writers on %i threads', p_processors_nb_threads, p_writer_nb_threads)
start_time = datetime.datetime.now()
# Set extra properties to readers
for reader in self.readers:
reader['reader'].counters = self.counters
reader['reader'].log_queue = log_queue
reader['reader'].log_level = logger.level
reader['reader'].formatter = formatter
# Set extra properties to writer
if self.writer is not None:
self.writer.counters = self.counters
self.writer.log_queue = log_queue
self.writer.log_level = logger.level
self.writer.formatter = formatter
read_worker = [Process(target=reader['reader'].scan_and_queue, args=(self.in_queue,), kwargs=(reader['args'])) for reader in self.readers]
process_worker = [Process(target=get_and_parse, args=(self.in_queue, self.out_queue, self.process, self.counters, log_queue, logger.level, formatter), kwargs=(self.process_args)) for i in range(p_processors_nb_threads)]
# writers are optionnal
if self.writer is not None:
write_worker = [Process(target=self.writer.dequeue_and_store, args=(self.out_queue,), kwargs=(self.writer_store_args)) for i in range(p_writer_nb_threads)]
else:
write_worker = []
# Running workers
for work in read_worker:
work.start()
for work in process_worker:
work.start()
for work in write_worker:
work.start()
# Waiting for workers to end :
# worker.join() blocks the programm till the worker ends
logger.info('Waiting for reader to finish')
for work in read_worker:
# Waiting for all reader to finish their jobs
work.join()
# At this point, reading is finished. We had a poison pill for each consumer of read queue :
for i in range(len(process_worker)):
self.in_queue.put(None)
logger.info('Waiting for processors to finish')
for work in process_worker:
# Waiting for all processors to finish their jobs
work.join()
# At this point, processing is finished. We had a poison pill for each consumer of write queue :
for i in range(len(write_worker)):
self.out_queue.put(None)
logger.info('Waiting for writers to finish')
for work in write_worker:
# Waiting for all writers to finish their jobs
work.join()
elsapsed_time = datetime.datetime.now() - start_time
logger.info('Elapsed time : %ss' % elsapsed_time.total_seconds())
avg_time = 0
nb_items = self.counters['nb_items_scanned'].value
if nb_items:
avg_time = 1000*self.counters['scan_time'].value / nb_items
logger.info('{0} items scanned ({1}ms)'.format(nb_items, avg_time))
avg_time = 0
avg_time_idle = 0
nb_items = self.counters['nb_items_processed'].value
if nb_items:
avg_time = 1000*self.counters['real_process_time'].value / nb_items
avg_time_idle = 1000*self.counters['idle_process_time'].value / nb_items
logger.info('{0} items processed (process : {1}ms / idle : {2}ms)'.format(nb_items, avg_time, avg_time_idle))
avg_time = 0
nb_items = self.counters['nb_items_stored'].value
if nb_items:
avg_time = 1000*self.counters['whole_storage_time'].value / nb_items
logger.info('{0} items stored ({1}ms)'.format(nb_items, avg_time))
nb_items = self.counters['nb_items_error'].value
logger.info('{0} items error'.format(nb_items))
# Stop listening for log messages
listener.stop()
def launch_workers(
stop_watchdog_event: threading.Event(),
exp_key: str,
n_cpu_workers: int = None,
gpu_ids: List[int] = None,
n_workers_per_gpu: int = 1,
reserve_timeout: float = 30.0,
workdir: str = ".",
mongo_port_address: str = "localhost:1234/scvi_db",
multiple_hosts: bool = False,
):
"""Launches the local workers which are going to run the jobs required by the minimization process.
Terminates when the worker_watchdog call finishes.
Specifically, first ``n_cpu_workers`` CPU workers are launched in their own spawned process.
Then, ``n_gpu_workers`` are launched per GPU in ``gpu_ids``, also in their own spawned process.
The use of spawned processes (each have their own python interpreter) is mandatory for compatiblity with CUDA.
See https://pytorch.org/docs/stable/notes/multiprocessing.html for more information.
:param stop_watchdog_event: When set, this event stops the watchdog Thread
which checks that local workers are still running.
:param exp_key: This key is used by hyperopt as a suffix to the part of the MongoDb
which corresponds to the current experiment. In particular, it has to be passed to ``MongoWorker``.
:param n_cpu_workers: Number of cpu workers to launch.
:param gpu_ids: Ids of the GPUs to use. If None defaults to all GPUs found by ``torch``.
Note that considered gpu ids are int from ``0`` to ``torch.cuda.device_count()``.
:param n_workers_per_gpu: Number of workers ton launch per gpu found by ``torch``.
:param reserve_timeout: Amount of time, in seconds, a worker tries to reserve a job for
before throwing a ``ReserveTimeout`` Exception.
:param fmin_timeout: Amount of time, in seconds, ``fmin_process`` has to terminate
after all workers have died - before throwing a ``FminTimeoutError``.
If ``multiple_hosts`` is set to ``True``, this is set to None to disable the timineout behaviour.
:param workdir: Directory where the workers
:param mongo_port_address: Address to the running MongoDb service.
:param multiple_hosts: ``True`` if launching workers form multiple hosts.
"""
# prepare parallel logging
_logging_queue = spawn_ctx.Queue()
listener = QueueListener(_logging_queue, DispatchHandler())
listener.start()
started_processes.append(listener)
if gpu_ids is None:
logger.debug("gpu_ids is None, defaulting to all gpus found by torch.")
gpu_ids = list(range(torch.cuda.device_count()))
if n_cpu_workers is None:
logger.debug(
"n_cpu_workers is None, defaulting to max(0, os.cpu_count() - 1).")
n_cpu_workers = max(0, os.cpu_count() - 1)
if not gpu_ids and not n_cpu_workers and not multiple_hosts:
raise ValueError("No hardware (cpu/gpu) selected/found.")
# log progress with queue and progress_listener
progress_queue = spawn_ctx.Queue()
prog_listener_kwargs = {
"progress_queue": progress_queue,
"logging_queue": _logging_queue,
}
prog_listener = spawn_ctx.Process(target=progress_listener,
kwargs=prog_listener_kwargs,
name="Progress listener")
prog_listener.start()
started_processes.append(prog_listener)
running_workers = []
# launch gpu workers
logger.info(
"Starting {n_workers_per_gpu} worker.s for each of the {n_gpus} gpu.s set for use/"
"found.".format(n_workers_per_gpu=n_workers_per_gpu,
n_gpus=len(gpu_ids)))
for gpu_id in gpu_ids:
for sub_id in range(n_workers_per_gpu):
worker_kwargs = {
"progress_queue": progress_queue,
"logging_queue": _logging_queue,
"exp_key": exp_key,
"workdir": workdir,
"gpu": True,
"hw_id": str(gpu_id),
"reserve_timeout": reserve_timeout,
"mongo_port_address": mongo_port_address,
}
p = spawn_ctx.Process(
target=hyperopt_worker,
kwargs=worker_kwargs,
name="Worker GPU " + str(gpu_id) + ":" + str(sub_id),
)
p.start()
running_workers.append(p)
# launch cpu workers
# TODO: add cpu affinity?
logger.info("Starting {n_cpu} cpu worker.s".format(n_cpu=n_cpu_workers))
for cpu_id in range(n_cpu_workers):
worker_kwargs = {
"progress_queue": progress_queue,
"logging_queue": _logging_queue,
"exp_key": exp_key,
"workdir": workdir,
"gpu": False,
"hw_id": str(cpu_id),
"reserve_timeout": reserve_timeout,
"mongo_port_address": mongo_port_address,
}
p = spawn_ctx.Process(
target=hyperopt_worker,
kwargs=worker_kwargs,
name="Worker CPU " + str(cpu_id),
)
# FIXME won't terminate if parent is killed (SIGKILL)
p.start()
running_workers.append(p)
started_processes.extend(running_workers)
# wait or return if all workers have died
workers_watchdog(running_workers=running_workers,
stop_event=stop_watchdog_event)
logger.debug(
"Worker watchdog finished, terminating workers and closing listener.")
for worker in running_workers:
if worker.is_alive():
worker.terminate()
listener.stop()
prog_listener.terminate()
