improve logging

This commit is contained in:
2020-11-03 20:53:01 +01:00
parent 81f9447709
commit 2bcc57a68c
2 changed files with 43 additions and 40 deletions

View File

@@ -25,13 +25,13 @@ async def task(event, task_id):
### FileManager ### FileManager
FileManager moves, copy or deletes files and/or directories following a list of *rules*. FileManager moves, copy or deletes files and/or directories following a list of *rules*.
A rule holds an *action* (move, copy or delete) and a regular expression *src_re*. The FileManager task will be executed if *src_re* matches the path of an event. If the action is copy or move, the destination path *dst_re* is mandatory. If *auto_create* is True, possibly missing subdirectories in *dst_re* are automatically created. If *action* is delete and *rec* is True, non-empty directories will be deleted recursively. It is possible to use Regex subgroups or named-subgroups in *src_re* and *dst_re*. A rule holds an *action* (move, copy or delete) and a regular expression *src_re*. The FileManager task will be executed if *src_re* matches the path of an event. If the action is copy or move, the destination path *dst_re* is mandatory. If *auto_create* is True, possibly missing subdirectories in *dst_re* are automatically created. If *action* is delete and *rec* is True, non-empty directories will be deleted recursively. It is possible to use Regex subgroups or named-subgroups in *src_re* and *dst_re*. Use *logname* in log messages.
```python ```python
rule = Rule( rule = Rule(
action="move", src_re="^/src_path/(?P<path>.*).to_move$", action="move", src_re="^/src_path/(?P<path>.*).to_move$",
dst_re="/dst_path/\g<path>", auto_create=False, rec=False) dst_re="/dst_path/\g<path>", auto_create=False, rec=False)
fm = FileManager(rules=[rule]) fm = FileManager(rules=[rule], logname="FileManager")
``` ```
FileManager provides a task **fm.task**. FileManager provides a task **fm.task**.
@@ -40,7 +40,7 @@ pyinotifyd has different schedulers to schedule tasks with an optional delay. Th
### TaskScheduler ### TaskScheduler
TaskScheduler schedules *task* with an optional *delay* in seconds. Use the *files* and *dirs* arguments to schedule tasks only for files and/or directories. TaskScheduler schedules *task* with an optional *delay* in seconds. Use the *files* and *dirs* arguments to schedule tasks only for files and/or directories.
The *logname* argument is used to set a custom name for log messages. All arguments except for *task* are optional. Use *logname* in log messages. All arguments except for *task* are optional.
```python ```python
s = TaskScheduler(task=task, files=True, dirs=False, delay=0, logname="TaskScheduler") s = TaskScheduler(task=task, files=True, dirs=False, delay=0, logname="TaskScheduler")
``` ```

View File

@@ -33,15 +33,15 @@ __version__ = "0.0.1"
class Task: class Task:
def __init__(self, event, delay, task_id, task, callback=None, def __init__(self, event, delay, task_id, task, callback=None,
logname="Task"): logname=None):
self._event = event self._event = event
self._path = event.pathname self._path = event.pathname
self._delay = delay self._delay = delay
self.task_id = task_id self._task_id = task_id
self._job = task self._job = task
self._callback = callback self._callback = callback
self._task = None self._task = None
self._log = logging.getLogger(logname) self._log = logging.getLogger((logname or self.__class__.__name__))
async def _start(self): async def _start(self):
if self._delay > 0: if self._delay > 0:
@@ -50,9 +50,9 @@ class Task:
if self._callback is not None: if self._callback is not None:
self._callback(self._event) self._callback(self._event)
self._task = None self._task = None
self._log.info(f"execute task {self.task_id}") self._log.info(f"execute task {self._task_id}")
await asyncio.shield(self._job(self._event, self.task_id)) await asyncio.shield(self._job(self._event, self._task_id))
self._log.info(f"task {self.task_id} finished") self._log.info(f"task {self._task_id} finished")
def start(self): def start(self):
if self._task is None: if self._task is None:
@@ -87,8 +87,7 @@ class TaskList:
class TaskScheduler: class TaskScheduler:
def __init__(self, task, files, dirs, delay=0, def __init__(self, task, files, dirs, delay=0, logname=None):
logname="TaskScheduler"):
assert callable(task), \ assert callable(task), \
f"task: expected callable, got {type(task)}" f"task: expected callable, got {type(task)}"
self._task = task self._task = task
@@ -102,7 +101,7 @@ class TaskScheduler:
f"dirs: expected {type(bool)}, got {type(dirs)}" f"dirs: expected {type(bool)}, got {type(dirs)}"
self._dirs = dirs self._dirs = dirs
self._tasks = {} self._tasks = {}
self._log = logging.getLogger(logname) self._log = logging.getLogger((logname or self.__class__.__name__))
def _task_started(self, event): def _task_started(self, event):
path = event.pathname path = event.pathname
@@ -111,12 +110,12 @@ class TaskScheduler:
def schedule(self, event): def schedule(self, event):
self._log.debug(f"received {event}") self._log.debug(f"received {event}")
path = event.pathname
maskname = event.maskname.split("|", 1)[0]
if (not event.dir and not self._files) or \ if (not event.dir and not self._files) or \
(event.dir and not self._dirs): (event.dir and not self._dirs):
return return
path = event.pathname
maskname = event.maskname.split("|", 1)[0]
if path in self._tasks: if path in self._tasks:
task = self._tasks[path] task = self._tasks[path]
self._log.info(f"received event {maskname} on '{path}', " self._log.info(f"received event {maskname} on '{path}', "
@@ -147,11 +146,11 @@ class TaskScheduler:
class ShellScheduler(TaskScheduler): class ShellScheduler(TaskScheduler):
def __init__(self, cmd, task=None, logname="ShellScheduler", def __init__(self, cmd, task=None, logname=None, *args, **kwargs):
*args, **kwargs):
assert isinstance(cmd, str), \ assert isinstance(cmd, str), \
f"cmd: expected {type('')}, got {type(cmd)}" f"cmd: expected {type('')}, got {type(cmd)}"
self._cmd = cmd self._cmd = cmd
logname = (logname or self.__class__.__name__)
super().__init__(*args, task=self.task, logname=logname, **kwargs) super().__init__(*args, task=self.task, logname=logname, **kwargs)
async def task(self, event, task_id): async def task(self, event, task_id):
@@ -189,8 +188,8 @@ class EventMap:
for flag, task in event_map.items(): for flag, task in event_map.items():
self.set(flag, task) self.set(flag, task)
def get(self): def items(self):
return self._map return self._map.items()
def set(self, flag, values): def set(self, flag, values):
assert flag in EventMap.flags, \ assert flag in EventMap.flags, \
@@ -233,12 +232,12 @@ class Watch:
def event_notifier(self, wm, loop): def event_notifier(self, wm, loop):
handler = pyinotify.ProcessEvent() handler = pyinotify.ProcessEvent()
mask = False mask = False
for flag, values in self.event_map.get().items(): for flag, values in self.event_map.items():
setattr(handler, f"process_{flag}", TaskList(values).execute) setattr(handler, f"process_{flag}", TaskList(values).execute)
if not mask: if mask:
mask = EventMap.flags[flag]
else:
mask = mask | EventMap.flags[flag] mask = mask | EventMap.flags[flag]
else:
mask = EventMap.flags[flag]
wm.add_watch(self.path, mask, rec=self.rec, auto_add=self.auto_add, wm.add_watch(self.path, mask, rec=self.rec, auto_add=self.auto_add,
do_glob=True) do_glob=True)
@@ -266,7 +265,7 @@ class Rule:
class FileManager: class FileManager:
def __init__(self, rules, logname="FileManager"): def __init__(self, rules, logname=None):
if not isinstance(rules, list): if not isinstance(rules, list):
rules = [rules] rules = [rules]
@@ -275,7 +274,7 @@ class FileManager:
f"rules: expected {type(Rule)}, got {type(rule)}" f"rules: expected {type(Rule)}, got {type(rule)}"
self._rules = rules self._rules = rules
self._log = logging.getLogger(logname) self._log = logging.getLogger((logname or self.__class__.__name__))
def add_rule(self, *args, **kwargs): def add_rule(self, *args, **kwargs):
self._rules.append(Rule(*args, **kwargs)) self._rules.append(Rule(*args, **kwargs))
@@ -362,40 +361,43 @@ class PyinotifydConfig:
f"watches: expected {type(Watch)}, got {type(watch)}" f"watches: expected {type(Watch)}, got {type(watch)}"
async def shutdown(signame, notifiers, timeout=30): async def shutdown(signame, notifiers, logname, timeout=30):
logging.info(f"got signal {signame}, shutdown ...") log = logging.getLogger(logname)
log.info(f"got signal {signame}, shutdown ...")
for notifier in notifiers: for notifier in notifiers:
notifier.stop() notifier.stop()
pending = [t for t in asyncio.all_tasks() pending = [t for t in asyncio.all_tasks()
if t is not asyncio.current_task()] if t is not asyncio.current_task()]
if len(pending) > 0: if len(pending) > 0:
logging.info( log.info(
f"graceful shutdown, waiting {timeout}s " f"graceful shutdown, waiting {timeout}s "
f"for remaining tasks to complete") f"for remaining tasks to complete")
try: try:
future = asyncio.gather(*pending) future = asyncio.gather(*pending)
await asyncio.wait_for(future, timeout) await asyncio.wait_for(future, timeout)
except asyncio.TimeoutError: except asyncio.TimeoutError:
logging.warning( log.warning(
"forcefully terminate remaining tasks") "forcefully terminate remaining tasks")
future.cancel() future.cancel()
future.exception() future.exception()
logging.info("shutdown") log.info("shutdown")
asyncio.get_event_loop().stop() asyncio.get_event_loop().stop()
def main(): def main():
myname = "pyinotifyd"
parser = argparse.ArgumentParser( parser = argparse.ArgumentParser(
description="pyinotifyd", description=myname,
formatter_class=lambda prog: argparse.HelpFormatter( formatter_class=lambda prog: argparse.HelpFormatter(
prog, max_help_position=45, width=140)) prog, max_help_position=45, width=140))
parser.add_argument( parser.add_argument(
"-c", "-c",
"--config", "--config",
help="path to config file (defaults to /etc/pyinotifyd/config.py)", help=f"path to config file (defaults to /etc/{myname}/config.py)",
default="/etc/pyinotifyd/config.py") default=f"/etc/{myname}/config.py")
parser.add_argument( parser.add_argument(
"-d", "-d",
"--debug", "--debug",
@@ -409,19 +411,21 @@ def main():
args = parser.parse_args() args = parser.parse_args()
if args.version: if args.version:
print(f"pyinotifyd ({__version__})") print(f"{myname} ({__version__})")
sys.exit(0) sys.exit(0)
log = logging.getLogger(myname)
try: try:
cfg = {} cfg = {}
with open(args.config, "r") as c: with open(args.config, "r") as c:
exec(c.read(), globals(), cfg) exec(c.read(), globals(), cfg)
cfg = cfg["pyinotifyd_config"] cfg = cfg[f"{myname}_config"]
assert isinstance(cfg, PyinotifydConfig), \ assert isinstance(cfg, PyinotifydConfig), \
f"pyinotifyd_config: expected {type(PyinotifydConfig)}, " \ f"{myname}_config: expected {type(PyinotifydConfig)}, " \
f"got {type(cfg)}" f"got {type(cfg)}"
except Exception as e: except Exception as e:
logging.exception(f"error in config file: {e}") log.exception(f"error in config file: {e}")
sys.exit(1) sys.exit(1)
console = logging.StreamHandler() console = logging.StreamHandler()
@@ -442,17 +446,16 @@ def main():
loop = asyncio.get_event_loop() loop = asyncio.get_event_loop()
notifiers = [] notifiers = []
for watch in cfg.watches: for watch in cfg.watches:
logging.info(f"start watching '{watch.path}'") log.info(f"start watching '{watch.path}'")
notifiers.append(watch.event_notifier(wm, loop)) notifiers.append(watch.event_notifier(wm, loop))
for signame in ["SIGINT", "SIGTERM"]: for signame in ["SIGINT", "SIGTERM"]:
loop.add_signal_handler(getattr(signal, signame), loop.add_signal_handler(getattr(signal, signame),
lambda: asyncio.ensure_future( lambda: asyncio.ensure_future(
shutdown(signame, notifiers, timeout=cfg.shutdown_timeout))) shutdown(signame, notifiers, myname,
timeout=cfg.shutdown_timeout)))
loop.run_forever() loop.run_forever()
loop.close() loop.close()
sys.exit(0) sys.exit(0)