From 9e2e7443df4496b1a695a31ac079392bef9b7987 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Tue, 11 Jun 2019 00:47:53 +0300 Subject: [PATCH 01/18] logging: reorg initialization for sanity and cleanliness - a run-once `initialize` method takes care of it all - removed `set_width`, `set_coloring`, `set_graphics` - the env-var `TERM_COLOR_SUPPORT` is no longer checked - the env-var `EASYPY_LOG_INDENTATION` is no longer checked - instead of updating `globals()`, update a `G` singleton --- CHANGELOG.md | 8 ++ easypy/humanize.py | 7 +- easypy/logging.py | 266 ++++++++++++++++++++++++++------------------- tests/conftest.py | 7 +- 4 files changed, 169 insertions(+), 119 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 3b0801be..81ac0822 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Changed +- Logging Initialization + - a run-once `initialize` method takes care of it all + - removed `set_width`, `set_coloring`, `set_graphics` + - the env-var `TERM_COLOR_SUPPORT` is no longer checked + - the env-var `EASYPY_LOG_INDENTATION` is no longer checked + + ## [0.3.0] - 2019-06-10 ### Added diff --git a/easypy/humanize.py b/easypy/humanize.py index c3fad765..d1493c73 100644 --- a/easypy/humanize.py +++ b/easypy/humanize.py @@ -214,10 +214,11 @@ def indent(self, fmt, *args, **kwargs): def render(self, width=None, textual=None, prune=False, file=None, overflow='ignore', edges=True): if width is None: - from .logging import TERM_WIDTH as width + from .logging import G + width, _ = os.get_terminal_size() if G.IS_A_TTY else [120, 0] if textual is None: - from .logging import GRAPHICAL - textual = not GRAPHICAL + from .logging import G + textual = not G.GRAPHICAL buff = file if file else StringIO() G = self.TEXTUAL_BOX if textual else self.NICE_BOX diff --git a/easypy/logging.py b/easypy/logging.py index 2961c429..fea57db2 100644 --- a/easypy/logging.py +++ b/easypy/logging.py @@ -14,80 +14,59 @@ from collections import OrderedDict from easypy.colors import colorize, uncolored -from easypy.humanize import compact as _compact +from easypy.humanize import compact from easypy.timing import timing as timing_context, Timer from easypy.threadtree import ThreadContexts from easypy.contexts import contextmanager - -logging.INFO1 = logging.INFO+1 -logging.addLevelName(logging.INFO1, "INFO1") +from easypy.tokens import if_auto, AUTO +from easypy.misc import at_least CLEAR_EOL = '\x1b[0K' -IS_A_TTY = sys.stdout.isatty() - -LOG_WITH_COLOR=None -def compact(msg): - raise NotImplementedError() - -def set_width(TERM_WIDTH): - if TERM_WIDTH in (True, None): - TERM_WIDTH, _ = os.get_terminal_size() - TERM_WIDTH = max(TERM_WIDTH, 120) - if TERM_WIDTH: - compact = lambda line: _compact(line, TERM_WIDTH-5) - else: - TERM_WIDTH = 0 - compact = lambda line: line - globals().update(locals()) - -def set_coloring(enabled): - global LOG_WITH_COLOR - LOG_WITH_COLOR = enabled - if enabled: - from easypy.colors import RED, GREEN, BLUE, WHITE, DARK_GRAY - else: - RED = GREEN = BLUE = WHITE = DARK_GRAY = lambda txt, *_, **__: txt - globals().update(locals()) +logging.INFO1 = logging.INFO + 1 +logging.addLevelName(logging.INFO1, "INFO1") -# All this expected to be set by set_graphics call -LINE = None -DOUBLE_LINE = None -INDENT_SEGMENT = None -INDENT_OPEN = None -INDENT_CLOSE = None -INDENT_EXCEPTION = None +class Graphics: -def set_graphics(GRAPHICAL): - if GRAPHICAL: + class Graphical: LINE = "─" DOUBLE_LINE = "═" - INDENT_SEGMENT = " │ " - INDENT_OPEN = " ├───┮ " - INDENT_CLOSE = " ╰╼" - INDENT_EXCEPTION = " ╘═" - else: + INDENT_SEGMENT = " │ " # noqa + INDENT_OPEN = " ├───┮ " # noqa + INDENT_CLOSE = " ╰╼" # noqa + INDENT_EXCEPTION = " ╘═" # noqa + + class ASCII: LINE = "-" DOUBLE_LINE = "=" - INDENT_SEGMENT = "..| " - INDENT_OPEN = "..|---+ " - INDENT_CLOSE = " '-" - INDENT_EXCEPTION = " '=" - globals().update(locals()) + INDENT_SEGMENT = "..| " # noqa + INDENT_OPEN = "..|---+ " # noqa + INDENT_CLOSE = " '-" # noqa + INDENT_EXCEPTION = " '=" # noqa + + +class G: + """ + This class is not to be initialized. + It is simply a namespace, container for lazily determined settings for this logging module + """ -set_width(IS_A_TTY) -set_coloring(IS_A_TTY or os.environ.get('TERM_COLOR_SUPPORT')) -set_graphics(IS_A_TTY or os.environ.get('TERM_COLOR_SUPPORT')) + initialized = False + + IS_A_TTY = None + GRAPHICAL = None + COLORING = None + GRPH = Graphics.ASCII LEVEL_COLORS = { - logging.DEBUG: "DARK_GRAY", - logging.INFO: "GRAY", + logging.DEBUG: "DARK_GRAY", + logging.INFO: "GRAY", logging.WARNING: "YELLOW", - logging.ERROR: "RED" - } + logging.ERROR: "RED" +} def get_level_color(level): @@ -101,16 +80,17 @@ def get_level_color(level): LEVEL_COLORS[level] = color return color -INDENT_COLORS = [ - ("DARK_%s<<{}>>" % color.upper()).format - for color in "GREEN BLUE MAGENTA CYAN YELLOW".split()] -random.shuffle(INDENT_COLORS) - class LogLevelClamp(logging.Filterer): + """ + Log-records with a log-level that is too high are clamped down. + Used internally by the ``ProgressBar`` + """ + def __init__(self, level=logging.DEBUG): self.level = level self.name = logging.getLevelName(level) + def filter(self, record): if record.levelno > self.level: record.levelname, record.levelno = self.name, self.level @@ -185,9 +165,9 @@ def formatMessage(self, record): if not hasattr(record, "levelcolor"): record.levelcolor = get_level_color(record.levelno) msg = super().formatMessage(record) - if IS_A_TTY: + if G.IS_A_TTY: msg = '\r' + msg + CLEAR_EOL - return colorize(msg) if LOG_WITH_COLOR else uncolored(msg) + return colorize(msg) if G.COLORING else uncolored(msg) try: @@ -209,11 +189,6 @@ def format(self, record): return yaml.dump(vars(record), Dumper=Dumper) + "\n---\n" -def configure_contextual_logging(_ctx=ExitStack(), **kw): - indentation = int(os.getenv("EASYPY_LOG_INDENTATION", "0")) - _ctx.enter_context(THREAD_LOGGING_CONTEXT(indentation=indentation, **kw)) - - THREAD_LOGGING_CONTEXT = ThreadContexts(counters="indentation", stacks="context") get_current_context = THREAD_LOGGING_CONTEXT.flatten @@ -239,6 +214,8 @@ def __init__(self): self._thread = None self._lock = threading.RLock() self._depth = 0 + self._term_width, _ = os.get_terminal_size() if G.IS_A_TTY else [0, 0] + self._term_width = at_least(120, self._term_width) def loop(self): wait_seq = cycle(self.WAITING) @@ -261,13 +238,13 @@ def loop(self): else: hanging +=1 - anim = WHITE(wait_symb+progress_symb) + anim = G.WHITE(wait_symb+progress_symb) elapsed = self._timer.elapsed.render(precision=0).rjust(8) if hanging >= (5*10*60): # ~5 minutes with no log messages - elapsed = RED(elapsed) + elapsed = G.RED(elapsed) else: - elapsed = BLUE(elapsed) + elapsed = G.BLUE(elapsed) line = elapsed + self._last_line.rstrip() line = line.replace("__PB__", anim) @@ -278,19 +255,21 @@ def loop(self): def progress(self, record): if not self._thread: return + if record.levelno >= logging.DEBUG: record.drawing = "__PB__" + record.drawing[2:] - self._last_line = compact(uncolored(self._format(record).split("\n")[0]).strip()[8:]) + txt = uncolored(self._format(record).split("\n")[0]).strip()[8:] + self._last_line = compact(txt, self._term_width - 5) self._event.set() def set_message(self, msg): - msg = msg.replace("|..|", "|__PB__"+INDENT_SEGMENT[3]) - self._last_line = "|" + compact(msg) + msg = msg.replace("|..|", "|__PB__" + G.graphics.INDENT_SEGMENT[3]) + self._last_line = "|" + compact(msg, self._term_width - 5) self._event.set() @contextmanager def __call__(self): - if not GRAPHICAL: + if not G.GRAPHICAL: yield self return @@ -332,6 +311,13 @@ class AbortedException(BaseException): class ContextLoggerMixin(object): + """ + A mixin class that provides easypy's logging functionality via the built-in logging's Logger objects: + - context and indentation + - per-thread logging supression and soloing + - progress-bar support + - and more... + """ _debuggifier = LogLevelClamp() @@ -363,8 +349,8 @@ def solo(self): @contextmanager def indented(self, header=None, *args, level=logging.INFO1, timing=True, footer=True): - header = compact((header % args) if header else "") - self._log(level, "WHITE@{%s}@" % header, (), extra=dict(drawing=INDENT_OPEN)) + header = (header % args) if header else "" + self._log(level, "WHITE@{%s}@" % header, (), extra=dict(drawing=G.graphics.INDENT_OPEN)) with ExitStack() as stack: stack.enter_context(THREAD_LOGGING_CONTEXT(indentation=1)) @@ -382,15 +368,15 @@ def footer_log(color, title, drawing): try: yield except (KeyboardInterrupt, AbortedException): - footer_log("CYAN", "ABORTED", INDENT_EXCEPTION) + footer_log("CYAN", "ABORTED", G.graphics.INDENT_EXCEPTION) raise except GeneratorExit: - footer_log("DARK_GRAY", "DONE", INDENT_CLOSE) + footer_log("DARK_GRAY", "DONE", G.graphics.INDENT_CLOSE) except: - footer_log("RED", "FAILED", INDENT_EXCEPTION) + footer_log("RED", "FAILED", G.graphics.INDENT_EXCEPTION) raise else: - footer_log("DARK_GRAY", "DONE", INDENT_CLOSE) + footer_log("DARK_GRAY", "DONE", G.graphics.INDENT_CLOSE) def error_box(self, *exc, extra=None): if len(exc)==1: @@ -400,8 +386,8 @@ def error_box(self, *exc, extra=None): else: typ, exc, tb = exc header = "%s.%s" % (typ.__module__, typ.__name__) - self.error("YELLOW@{%s}@ RED@{%s}@", header, LINE*(80-len(header)-1), extra=dict(drawing=RED(INDENT_OPEN))) - with THREAD_LOGGING_CONTEXT(indentation=1, drawing=RED(INDENT_SEGMENT)): + self.error("YELLOW@{%s}@ RED@{%s}@", header, G.graphics.LINE*(80-len(header)-1), extra=dict(drawing=G.RED(G.graphics.INDENT_OPEN))) + with THREAD_LOGGING_CONTEXT(indentation=1, drawing=G.RED(G.graphics.INDENT_SEGMENT)): if hasattr(exc, "render") and callable(exc.render): exc_text = exc.render() elif tb: @@ -415,12 +401,12 @@ def error_box(self, *exc, extra=None): if extra: for line in extra.splitlines(): self.error(line) - self.error("RED@{%s}@", DOUBLE_LINE*80, extra=dict(drawing=RED(INDENT_EXCEPTION))) + self.error("RED@{%s}@", G.DOUBLE_LINE*80, extra=dict(drawing=G.RED(G.graphics.INDENT_EXCEPTION))) _progressing = False @contextmanager def progress_bar(self): - if not GRAPHICAL: + if not G.GRAPHICAL: with PROGRESS_BAR() as pb: yield pb return @@ -498,32 +484,6 @@ def cm(): return cm() -if not issubclass(logging.Logger, ContextLoggerMixin): - logging.Logger.__bases__ = logging.Logger.__bases__ + (ContextLoggerMixin,) - - def makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=None, extra=None, sinfo=None): - drawing = INDENT_SEGMENT - - rv = logging.Logger._makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=func, sinfo=sinfo) - if extra is not None: - drawing = extra.pop('drawing', drawing) - for key in extra: - if (key in ["message", "asctime"]) or (key in rv.__dict__): - raise KeyError("Attempt to overwrite %r in LogRecord" % key) - rv.__dict__[key] = extra[key] - - contexts = THREAD_LOGGING_CONTEXT.context - extra = THREAD_LOGGING_CONTEXT.flatten() - extra['context'] = "[%s]" % ";".join(contexts) if contexts else "" - rv.__dict__.update(dict(extra, **rv.__dict__)) - - indents = chain(repeat(INDENT_SEGMENT, rv.indentation), repeat(drawing, 1)) - rv.drawing = "".join(color(segment) for color, segment in zip(cycle(INDENT_COLORS), indents)) - return rv - - logging.Logger._makeRecord, logging.Logger.makeRecord = logging.Logger.makeRecord, makeRecord - - class HeartbeatHandler(logging.Handler): "Heartbeat notifications based on the application's logging activity" @@ -548,7 +508,7 @@ def emit(self, record): if (record.created - self.last_beat) > self.min_interval: try: log_message = self.format(record) - except: + except: # noqa log_message = "Log record formatting error (%s:#%s)" % (record.filename, record.lineno) self.beat(log_message=log_message, heartbeat=record.created) self.last_beat = record.created @@ -559,6 +519,7 @@ def emit(self, record): def log_context(method=None, **ctx): if not method: return partial(log_context, **ctx) + @wraps(method) def inner(*args, **kwargs): context = {k: fmt.format(*args, **kwargs) for k, fmt in ctx.items()} @@ -578,9 +539,9 @@ def __eq__(self, fname): #=====================#=====================#=====================# - _root = __file__[:__file__.find(os.sep.join(__name__.split(".")))] + def _trim(pathname, modname, cache={}): try: return cache[(pathname, modname)] @@ -593,3 +554,84 @@ def _trim(pathname, modname, cache={}): ret = cache[(pathname, modname)] = filter(None, elems) return ret + + +# ================================================================= + +def patched_makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=None, extra=None, sinfo=None): + drawing = G.graphics.INDENT_SEGMENT + + rv = logging.Logger._makeRecord(self, name, level, fn, lno, msg, args, exc_info, func=func, sinfo=sinfo) + if extra is not None: + drawing = extra.pop('drawing', drawing) + for key in extra: + if (key in ["message", "asctime"]) or (key in rv.__dict__): + raise KeyError("Attempt to overwrite %r in LogRecord" % key) + rv.__dict__[key] = extra[key] + + contexts = THREAD_LOGGING_CONTEXT.context + extra = THREAD_LOGGING_CONTEXT.flatten() + extra['context'] = "[%s]" % ";".join(contexts) if contexts else "" + rv.__dict__.update(dict(extra, **rv.__dict__)) + + indents = chain(repeat(G.graphics.INDENT_SEGMENT, rv.indentation), repeat(drawing, 1)) + rv.drawing = "".join(color(segment) for color, segment in zip(cycle(G.INDENT_COLORS), indents)) + return rv + + +def initialize(*, graphical=AUTO, coloring=AUTO, indentation=0, context={}): + """ + Initialize easypy's logging module. + Also injects easypy's ContextLoggerMixin into the builtin logging module. + + :param graphical: Whether to use unicode or ascii for graphical elements + :param coloring: Whether to use color in logging + :param indentation: The initial indentation level + :param context: The initial logging context attributes + """ + + if G.initialized: + logging.warning("%s is already initialized", __name__) + return + + G.IS_A_TTY = sys.stdout.isatty() + + # ===================== + # Graphics initialization + + G.GRAPHICAL = if_auto(graphical, G.IS_A_TTY) + G.graphics = Graphics.Graphical if G.GRAPHICAL else Graphics.ASCII + + # ===================== + # Coloring indentation + + G.COLORING = if_auto(coloring, G.IS_A_TTY) + if G.COLORING: + from easypy.colors import RED, GREEN, BLUE, WHITE, DARK_GRAY + G.INDENT_COLORS = [ + ("DARK_%s<<{}>>" % color.upper()).format + for color in "GREEN BLUE MAGENTA CYAN YELLOW".split()] + random.shuffle(G.INDENT_COLORS) + else: + RED = GREEN = BLUE = WHITE = DARK_GRAY = lambda txt, *_, **__: txt + G.INDENT_COLORS = [lambda s: s] + + G.RED = RED + G.GREEN = GREEN + G.BLUE = BLUE + G.WHITE = WHITE + G.DARK_GRAY = DARK_GRAY + + # ===================== + # Context + + G._ctx = ExitStack() + G._ctx.enter_context(THREAD_LOGGING_CONTEXT(indentation=indentation, **context)) + + # ===================== + # Mixin injection + + logging.Logger.__bases__ = logging.Logger.__bases__ + (ContextLoggerMixin,) + logging.Logger._makeRecord, logging.Logger.makeRecord = logging.Logger.makeRecord, patched_makeRecord + + G.initialized = True diff --git a/tests/conftest.py b/tests/conftest.py index f64359fb..ce6c1194 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -5,12 +5,11 @@ import logging -import logging.config -from easypy import logging as easypy_logging + logging.addLevelName(logging.WARN, "WARN") # instead of "WARNING", so that it takes less space... logging.addLevelName(logging.NOTSET, "NA") # instead of "NOTSET", so that it takes less space... -if not issubclass(logging.Logger, easypy_logging.ContextLoggerMixin): - logging.Logger.__bases__ = logging.Logger.__bases__ + (easypy_logging.ContextLoggerMixin,) +from easypy.logging import initialize +initialize() logging.basicConfig(level=logging.DEBUG, format='%(asctime)s|%(process)2s:%(threadName)-25s|%(name)-40s|%(levelname)-5s|%(funcName)-30s |%(message)s') From 12b86faa218c3b5d5ccbeadf69d10f7518cf94bd Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Tue, 11 Jun 2019 01:24:47 +0300 Subject: [PATCH 02/18] ziplog: added commonly found timestamp patterns, and tests --- CHANGELOG.md | 1 + easypy/ziplog.py | 39 +++++++++++++++++++++++++++-------- tests/test_ziplog.py | 49 ++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 81 insertions(+), 8 deletions(-) create mode 100644 tests/test_ziplog.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 81ac0822..403fc6a8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - removed `set_width`, `set_coloring`, `set_graphics` - the env-var `TERM_COLOR_SUPPORT` is no longer checked - the env-var `EASYPY_LOG_INDENTATION` is no longer checked +- ziplog - added commonly found timestamp patterns ## [0.3.0] - 2019-06-10 diff --git a/easypy/ziplog.py b/easypy/ziplog.py index c8d587f4..565187bc 100644 --- a/easypy/ziplog.py +++ b/easypy/ziplog.py @@ -1,8 +1,8 @@ import re import time +from datetime import datetime from queue import PriorityQueue from .colors import uncolored -from .logging import PROGRESS_BAR TIMESTAMP_PATTERN = "%Y-%m-%d %H:%M:%S" @@ -13,14 +13,37 @@ def to_timestamp(t): YEAR = time.strftime("%Y") -TIMESTAMP_GETTERS = ( +MONTH = time.strftime("%m") +DAY = time.strftime("%d") - (re.compile("^(\w{3} +\d+ +\d+:\d+:\d+)"), +TIMESTAMP_GETTERS = [ + + # 01:21:27 + (re.compile(r"^(\d+:\d+:\d+)"), + lambda ts: time.mktime(time.strptime("%s-%s-%s %s" % (YEAR, MONTH, DAY, ts), "%Y-%m-%d %H:%M:%S"))), + + # Apr 6 17:13:40 + (re.compile(r"^(\w{3} +\d+ +\d+:\d+:\d+)"), lambda ts: time.mktime(time.strptime("%s %s" % (YEAR, ts), "%Y %b %d %H:%M:%S"))), - (re.compile("(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}),(\d{3})\|"), - lambda ts, ms: time.mktime(time.strptime(ts, "%Y-%m-%d %H:%M:%S")) + float(ms)/100000), - ) + # 2018-12-15T02:11:06+0200 + (re.compile(r"^(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\+\d{4})"), + lambda ts: datetime.strptime(ts, '%Y-%m-%dT%H:%M:%S%z').timestamp()), + + # [2018/04/06 17:13:40.955356, + (re.compile(r"\[(\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2})\.(\d{6}),"), + lambda ts, ms: time.mktime(time.strptime(ts, "%Y/%m/%d %H:%M:%S")) + float(ms) / 1000000), + + # 2018-04-06 17:13:40,955 + # 2018-04-23 04:48:11,811| + (re.compile(r"(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}),(\d{3})[| ]"), + lambda ts, ms: time.mktime(time.strptime(ts, "%Y-%m-%d %H:%M:%S")) + float(ms) / 1000), + + # for strace logs + # 16255 15:08:52.554223 + (re.compile(r"\d+ (\d{2}:\d{2}:\d{2}).(\d{6})"), + lambda ts, ms: time.mktime(time.strptime("%s-%s-%s %s" % (YEAR, MONTH, DAY, ts), "%Y-%m-%d %H:%M:%S")) + float(ms) / 1000000), +] class TimestampedStream(object): @@ -65,7 +88,7 @@ def get_timestamp(self, line): return 0 -def iter_zipped_logs(*log_streams): +def iter_zipped_logs(*log_streams, prefix="DARK_GRAY@{> }@"): "Line iterator that merges lines from different log streams based on their timestamp" # A sorted queue of (timestamp, stream) tuples (lowest-timestamp first) @@ -73,7 +96,7 @@ def iter_zipped_logs(*log_streams): stream_names = [] for i, stream in enumerate(log_streams): if not isinstance(stream, tuple): - tstream = TimestampedStream(stream, "DARK_GRAY@{> }@") + tstream = TimestampedStream(stream, prefix) else: tstream = TimestampedStream(*stream) diff --git a/tests/test_ziplog.py b/tests/test_ziplog.py new file mode 100644 index 00000000..c30f1171 --- /dev/null +++ b/tests/test_ziplog.py @@ -0,0 +1,49 @@ + + +def test_ziplog(): + from io import StringIO + from easypy import ziplog + from textwrap import dedent + + streams = dedent(""" + 01:21:27 - 2 + 05:41:27 - 4 + ; + 16255 15:08:52.554223| - 5 + 16155 19:08:52.554223| - 11 + ; + 2018-04-01 04:48:11,811| - 1 + 2018-04-06 17:13:40,966 - 8 + ; + 2018-04-06T02:11:06+0200 - 3 + 2018-04-07T02:11:06+0200 - 12 + ; + 2018-04-06 18:13:40,966 - 10 + 2018-04-23 04:48:11,811| - 14 + ; + [2018/04/06 17:13:40.955356 - 7 + [2018/04/06 17:13:41.955356 - 9 + ; + Apr 6 17:13:40 - 6 + Apr 7 17:13:40 - 13 + ; + """) + + ziplog.YEAR = 2018 + ziplog.MONTH = 4 + ziplog.DAY = 6 + + streams = [StringIO(line.lstrip()) for line in streams.split(";")] + lines = ziplog.iter_zipped_logs(*streams, prefix="> ") + prev = 0 + print() + for line in lines: + print(line, end="") + cur = int(line.rpartition(" ")[-1]) + try: + assert cur == prev + 1, "line %s is out of place" % cur + except AssertionError: + for line in lines: + print(line, end="") + raise + prev = cur From 6058ffd5389d416619fedbcc6d5f0e7d43e3f92a Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Tue, 11 Jun 2019 01:33:31 +0300 Subject: [PATCH 03/18] logging: deprecate '&' for '|' when using logger.pipe() Also added docstrings --- easypy/logging.py | 27 ++++++++++++++++++++++++--- 1 file changed, 24 insertions(+), 3 deletions(-) diff --git a/easypy/logging.py b/easypy/logging.py index fea57db2..72c201bc 100644 --- a/easypy/logging.py +++ b/easypy/logging.py @@ -425,12 +425,23 @@ def silent_exception(self, message, *args, **kwargs): self.error(message, *args, **kwargs) self.debug('Traceback:', exc_info=True) - def __rand__(self, cmd): - return cmd & self.pipe(logging.INFO, logging.INFO) + def __ror__(self, cmd): + """ + Integration with plumbum's command objects for subprocess execution. + Pipe stderr and stdout lines into this logger (at level INFO) + """ + return cmd | self.pipe(logging.INFO, logging.INFO) + + __rand__ = __ror__ # for backwards compatibility def pipe(self, err_level=logging.DEBUG, out_level=logging.INFO, prefix=None, line_timeout=10 * 60, **kw): + """ + Integration with plumbum's command objects for subprocess execution. + Pipe stderr and stdout lines into this logger (at levels `err_level/out_level`) + Optionally use `prefix` for each line. + """ class LogPipe(object): - def __rand__(_, cmd): + def __ror__(_, cmd): popen = cmd if hasattr(cmd, "iter_lines") else cmd.popen() for out, err in popen.iter_lines(line_timeout=line_timeout, **kw): for level, line in [(out_level, out), (err_level, err)]: @@ -441,12 +452,22 @@ def __rand__(_, cmd): l = "%s: %s" % (prefix, l) self.log(level, l) return popen.returncode + __rand__ = __ror__ # for backwards compatibility + return LogPipe() def pipe_info(self, prefix=None, **kw): + """ + Integration with plumbum's command objects for subprocess execution. + Pipe stderr and stdout lines into this logger (both at level INFO) + """ return self.pipe(logging.INFO, logging.INFO, prefix=prefix, **kw) def pipe_debug(self, prefix=None, **kw): + """ + Integration with plumbum's command objects for subprocess execution. + Pipe stderr and stdout lines into this logger (both at level DEBUG) + """ return self.pipe(logging.DEBUG, logging.DEBUG, prefix=prefix, **kw) def info1(self, *args, **kwargs): From 92889cabfdfada61b943405ec54d10d38203e57b Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Tue, 11 Jun 2019 01:37:20 +0300 Subject: [PATCH 04/18] examples: example for initializing logging --- examples/logging_init.py | 197 +++++++++++++++++++++++++++++++++++++++ 1 file changed, 197 insertions(+) create mode 100644 examples/logging_init.py diff --git a/examples/logging_init.py b/examples/logging_init.py new file mode 100644 index 00000000..f7020844 --- /dev/null +++ b/examples/logging_init.py @@ -0,0 +1,197 @@ +import os +import logging +import logging.config +import logging.handlers + +from easypy.logging import initialize +from easypy.logging import get_console_handler + +logging.addLevelName(logging.WARN, "WARN") # instead of "WARNING", so that it takes less space... +logging.addLevelName(logging.NOTSET, "NA") # instead of "NOTSET", so that it takes less space... + + +LOG_PATH = "." +PRIMARY_LOG_FILE = os.path.join(LOG_PATH, 'easypy.log') +LOG_LEVEL = "INFO" + +if os.getenv('TERM_LOG_STDOUT'): + console_stream = 'stdout' +else: + console_stream = 'stderr' + + +CONFIG = { + 'version': 1, + 'disable_existing_loggers': False, + 'formatters': { + 'detailed': { + 'format': '%(asctime)s|%(process)2s:%(threadName)-25s|%(name)-40s|%(levelname)-5s|' + '%(funcName)-30s |%(host)-35s|%(message)s', + }, + 'console': { + '()': 'easypy.logging.ConsoleFormatter', + 'fmt': '%(levelcolor)s<<%(asctime)s|%(levelname)-5s|%(host)-40s>>|%(drawing)s%(message)s', + 'datefmt': '%H:%M:%S' + }, + 'yaml': { + '()': 'easypy.logging.YAMLFormatter', + 'allow_unicode': True, + 'explicit_start': True, + 'explicit_end': True, + 'encoding': 'utf-8', + }, + }, + 'filters': { + 'thread_control': { + '()': 'easypy.logging.ThreadControl' + } + }, + 'handlers': { + 'console': { + 'class': 'logging.StreamHandler', + 'formatter': "console", # if sys.stdout.isatty() else "detailed", + 'filters': ['thread_control'], + 'level': LOG_LEVEL, + 'stream': 'ext://sys.%s' % console_stream + }, + 'main_file': { + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': PRIMARY_LOG_FILE, + 'mode': 'w', + 'formatter': 'detailed', + 'level': 'DEBUG', + 'maxBytes': 2**20 * 10, + 'backupCount': 5, + 'delay': True, + 'encoding': 'utf-8', + }, + 'aux': { + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': os.path.join(LOG_PATH, 'aux.log'), + 'mode': 'w', + 'formatter': 'detailed', + 'level': 'DEBUG', + 'maxBytes': 2**20 * 10, + 'backupCount': 5, + 'delay': True, + 'encoding': 'utf-8', + }, + 'boto': { + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': os.path.join(LOG_PATH, 'boto.log'), + 'mode': 'w', + 'formatter': 'detailed', + 'level': 'DEBUG', + 'maxBytes': 2**20 * 10, + 'backupCount': 5, + 'delay': True, + 'encoding': 'utf-8', + }, + 'threads': { + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': os.path.join(LOG_PATH, 'threads.yaml.log'), + 'mode': 'w', + 'formatter': 'yaml', + 'level': 'DEBUG', + 'maxBytes': 2**20 * 100, + 'backupCount': 1, + 'delay': True, + 'encoding': 'utf-8', + }, + 'gevent': { + 'class': 'logging.handlers.RotatingFileHandler', + 'filename': os.path.join(LOG_PATH, 'gevent.log'), + 'mode': 'w', + 'formatter': 'detailed', + 'level': 'DEBUG', + 'maxBytes': 2**20 * 1, + 'backupCount': 1, + 'delay': True, + 'encoding': 'utf-8', + }, + 'progress': { + 'class': 'easypy.logging.ProgressHandler', + }, + }, + 'root': { + 'level': 'NOTSET', + 'handlers': ['console', 'main_file', 'progress'] + }, + 'loggers': { + 'threads': { + 'propagate': False, + 'handlers': ['threads'] + }, + 'gevent': { + 'propagate': False, + 'handlers': ['gevent'] + }, + } +} + + +REDIRECTIONS = { + 'aux': [ + 'paramiko', 'paramiko.transport', 'plumbum.shell', 'urllib3.connectionpool', 'urllib3.util.retry', + 'aux', 'requests.packages.urllib3.connectionpool', 'googleapiclient.discovery', + 'sentry.errors', 'wepy.devops.talker.verbose', 'easypy.threadtree', 'concurrent.futures', + 'easypy.concurrency.locks', + ], + 'boto': ['boto', 'boto3', 'botocore'] +} + + +for target, loggers in REDIRECTIONS.items(): + for name in loggers: + CONFIG['loggers'][name] = dict(propagate=False, handlers=[target, 'progress']) + + +_action = 0 + + +def handle_usr_signal(sig, frame): + extra = dict(host="---") + + def dump_stacks(): + from easypy.threadtree import get_thread_stacks + stacks = get_thread_stacks() + logging.info("\n%s", stacks, extra=extra) + + actions = {0: dump_stacks, 1: set_verbose, 2: set_info} + + global _action + func = actions[_action % len(actions)] + _action += 1 + logging.info("YELLOW<> -> CYAN<<%s>>", _action, func, extra=extra) + try: + func() + except: + pass + + +def configure(filename=None, no_heartbeats=False): + import socket + + HOSTNAME = socket.gethostname() + initialize(context=dict(host=HOSTNAME)) + + import signal + signal.signal(signal.SIGUSR2, handle_usr_signal) + + logging.config.dictConfig(CONFIG) + + +def set_level(level): + get_console_handler().setLevel(getattr(logging, level)) + + +def get_level(): + return logging.getLevelName(get_console_handler().level) + + +def set_verbose(): + set_level("DEBUG") + + +def set_info(): + set_level("INFO") From 40ffbddc997b85ce4a96f00c601eaa1902634670 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Tue, 11 Jun 2019 02:02:12 +0300 Subject: [PATCH 05/18] update changelog --- CHANGELOG.md | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 403fc6a8..c53c45fc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,7 +12,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - removed `set_width`, `set_coloring`, `set_graphics` - the env-var `TERM_COLOR_SUPPORT` is no longer checked - the env-var `EASYPY_LOG_INDENTATION` is no longer checked + +### Added - ziplog - added commonly found timestamp patterns +- Examples + - a skeleton for initializing logging with easypy + +### Deprecated +- use '|' instead of '&' for piping plumbum commands into loggers ## [0.3.0] - 2019-06-10 From a308e17a21e1a141e80a60769097e2216cbde1c7 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Sun, 16 Jun 2019 15:56:41 +0300 Subject: [PATCH 06/18] humanize: fix regex escaping --- easypy/humanize.py | 21 +++++++++++---------- 1 file changed, 11 insertions(+), 10 deletions(-) diff --git a/easypy/humanize.py b/easypy/humanize.py index d1493c73..8bf2e23c 100644 --- a/easypy/humanize.py +++ b/easypy/humanize.py @@ -121,15 +121,16 @@ def time_ago(t, now=None): INPUT_TIME_PATTERNS = [ ((re.compile(p[0]),) + tuple(p[1:])) for p in ( - ("(\d{1,2}/\d{1,2}-\d{1,2}:\d{1,2}:\d{1,2})", "%d/%m-%H:%M:%S", 1, 0), # 21/05-17:09:59 - ("(\d{4}-\d{1,2}-\d{1,2}(?P[T-])\d{1,2}:\d{1,2}:\d{1,2})(?:\d*\.\d*)?(?PZ)?", "%Y-%m-%d{sep}%H:%M:%S", 0, time.timezone), - ("(\d{4}-\d{1,2}-\d{1,2}-\d{1,2}:\d{1,2})", "%Y-%m-%d-%H:%M", 0, 0), - ("(\d{1,2}-\d{1,2}-\d{1,2}:\d{1,2})", "%m-%d-%H:%M", 1, 0), - ("(\w+\s+\d{1,2}\s+\d{1,2}:\d{1,2}:\d{1,2})", "%b %d %H:%M:%S", 1, 0), - ("(\d{1,2}-\d{1,2}:\d{1,2}:\d{1,2})", "%d-%H:%M:%S", 2, 0), - ("(\d{1,2}-\d{1,2}:\d{1,2})", "%d-%H:%M", 2, 0), - ("(\d{1,2}:\d{1,2}:\d{1,2})", "%H:%M:%S", 3, 0), - ("(\d{1,2}:\d{1,2})", "%H:%M", 3, 0), + (r"(\d{1,2}/\d{1,2}-\d{1,2}:\d{1,2}:\d{1,2})", "%d/%m-%H:%M:%S", 1, 0), # 21/05-17:09:59 + (r"(\d{4}-\d{1,2}-\d{1,2}(?P[T-])\d{1,2}:\d{1,2}:\d{1,2})(?:\d*\.\d*)?(?PZ)?", + "%Y-%m-%d{sep}%H:%M:%S", 0, time.timezone), + (r"(\d{4}-\d{1,2}-\d{1,2}-\d{1,2}:\d{1,2})", "%Y-%m-%d-%H:%M", 0, 0), + (r"(\d{1,2}-\d{1,2}-\d{1,2}:\d{1,2})", "%m-%d-%H:%M", 1, 0), + (r"(\w+\s+\d{1,2}\s+\d{1,2}:\d{1,2}:\d{1,2})", "%b %d %H:%M:%S", 1, 0), + (r"(\d{1,2}-\d{1,2}:\d{1,2}:\d{1,2})", "%d-%H:%M:%S", 2, 0), + (r"(\d{1,2}-\d{1,2}:\d{1,2})", "%d-%H:%M", 2, 0), + (r"(\d{1,2}:\d{1,2}:\d{1,2})", "%H:%M:%S", 3, 0), + (r"(\d{1,2}:\d{1,2})", "%H:%M", 3, 0), )] @@ -463,7 +464,7 @@ class TrimmingTemplate(str): """ - RE_NEW_STYLE_FORMATTERS = re.compile("{(\w+):([^}]*)}") + RE_NEW_STYLE_FORMATTERS = re.compile(r"{(\w+):([^}]*)}") def __init__(self, s): assert s == to_new_style_formatter(s), "Can't use old-style string formatting syntax" From fcfdc7b448fe30c785d205039d9c0da175ce4897 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Tue, 18 Jun 2019 16:08:40 +0300 Subject: [PATCH 07/18] collections: workaround python bug importing 'test.support' --- easypy/collections.py | 79 ++++++++++++++++++++++++++------------- easypy/typed_struct.py | 5 ++- tests/test_collections.py | 6 +++ 3 files changed, 63 insertions(+), 27 deletions(-) diff --git a/easypy/collections.py b/easypy/collections.py index 6b5a7cac..1daca2ad 100755 --- a/easypy/collections.py +++ b/easypy/collections.py @@ -16,14 +16,20 @@ from .exceptions import TException import sys + +from collections import OrderedDict as PythonOrderedDict +SUPPORT_GET_SIBLING = True + if sys.version_info[:2] >= (3, 5): # In order to support 'get_prev' and 'get_next', we need access to OrderedDict's internal .__map, # which we don't have in the C-implementation of the class in Python3.5 # This hack allows us to get to the pythonic implemenation of OrderedDict - from test.support import import_fresh_module - PythonOrderedDict = import_fresh_module('collections', blocked=['_collections']).OrderedDict -else: - from collections import OrderedDict as PythonOrderedDict + try: + from test.support import import_fresh_module + PythonOrderedDict = import_fresh_module('collections', blocked=['_collections']).OrderedDict + except ImportError: + # this happens on 3.6.7-8 due to a bug (https://bugzilla.redhat.com/show_bug.cgi?id=1651245) + SUPPORT_GET_SIBLING = False def _format_predicate(pred): @@ -553,27 +559,50 @@ def index(self, obj): if lookup_uid == uid: return i - def get_next(self, obj): - uid = self._get_object_uid(obj) - if uid not in self._objects: - raise ObjectNotFound(self, (), dict(key=uid),) - next_uid = self._objects._OrderedDict__map[uid].next - try: - key = next_uid.key - except AttributeError: - key = next_uid.next.key - return self._objects[key] - - def get_prev(self, obj): - uid = self._get_object_uid(obj) - if uid not in self._objects: - raise ObjectNotFound(self, (), dict(key=uid),) - prev_uid = self._objects._OrderedDict__map[uid].prev - try: - key = prev_uid.key - except AttributeError: - key = prev_uid.prev.key - return self._objects[key] + if SUPPORT_GET_SIBLING: + def get_next(self, obj): + uid = self._get_object_uid(obj) + if uid not in self._objects: + raise ObjectNotFound(self, (), dict(key=uid),) + next_uid = self._objects._OrderedDict__map[uid].next + try: + key = next_uid.key + except AttributeError: + key = next_uid.next.key + return self._objects[key] + + def get_prev(self, obj): + uid = self._get_object_uid(obj) + if uid not in self._objects: + raise ObjectNotFound(self, (), dict(key=uid),) + prev_uid = self._objects._OrderedDict__map[uid].prev + try: + key = prev_uid.key + except AttributeError: + key = prev_uid.prev.key + return self._objects[key] + else: + def get_next(self, obj): + from warning import warn + warn("Couldn't import a pure-python OrderedDict so this will be a O(n) operation") + + from itertools import cycle + l1, l2 = cycle(self._objects.values()), cycle(self._objects.values()) + next(l2) + for a, b in zip(l1, l2): + if obj == a: + return b + + def get_prev(self, obj): + from warning import warn + warn("Couldn't import a pure-python OrderedDict so this will be a O(n) operation") + + from itertools import cycle + l1, l2 = cycle(self._objects.values()), cycle(self._objects.values()) + next(l2) + for a, b in zip(l1, l2): + if obj == b: + return a def keys(self): return self._objects.keys() diff --git a/easypy/typed_struct.py b/easypy/typed_struct.py index fb2d8b4f..b42eb11e 100644 --- a/easypy/typed_struct.py +++ b/easypy/typed_struct.py @@ -2,8 +2,9 @@ from .exceptions import TException from .tokens import AUTO, MANDATORY -from .collections import ListCollection, PythonOrderedDict, iterable +from .collections import ListCollection, iterable from .bunch import Bunch, bunchify +from collections import OrderedDict class InvalidFieldType(TException): @@ -441,7 +442,7 @@ def __init__(self, **kwargs): return cls -class _TypedStructDslDict(PythonOrderedDict): +class _TypedStructDslDict(OrderedDict): def __init__(self, bases): super().__init__() for base in bases: diff --git a/tests/test_collections.py b/tests/test_collections.py index b8da77d3..e492bbd0 100644 --- a/tests/test_collections.py +++ b/tests/test_collections.py @@ -133,3 +133,9 @@ def test_filters_order(): with pytest.raises(AttributeError): filterd_l = l.select(lambda o: o.b > 4) + + +def test_simple_object_collection(): + S = SimpleObjectCollection(L, ID_ATTRIBUTE='id') + assert S.get_next(S['5']) == S['6'] + assert S.get_prev(S['5']) == S['4'] From df01f92478bc4cbbe3cdc0bfb0bf8cb08b76c06b Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Thu, 20 Jun 2019 00:17:11 +0300 Subject: [PATCH 08/18] random: added 'perchance', for a common random use-case --- easypy/random.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/easypy/random.py b/easypy/random.py index 7613f274..7e40ced0 100644 --- a/easypy/random.py +++ b/easypy/random.py @@ -53,3 +53,7 @@ def random_filename(length=(3, 50)): def random_buf(size): assert size < 5 * 2**20, "This is too big for a buffer (%s)" % size return random_string(size).encode("latin-1") + + +def perchance(probabilty): + return random.random() <= probabilty From faa958a65315a95b5ae519086733b522f6065e0e Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Sun, 30 Jun 2019 18:03:35 +0300 Subject: [PATCH 09/18] colors: add '@[..]@' as coloring markup delimiter --- easypy/colors.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/easypy/colors.py b/easypy/colors.py index 82bd55b6..b87c8ec4 100644 --- a/easypy/colors.py +++ b/easypy/colors.py @@ -60,17 +60,19 @@ r"[A-Z_]+(?:\([^\)]+\))?" r"(?:" r"(?:\<\<).*?(?:\>\>)|" - r"(?:\@\{).*?(?:\}\@)" + r"(?:\@\{).*?(?:\}\@)|" + r"(?:\@\[).*?(?:\]\@)" "))") # this regex is used to parse the color markup into a foreground color, optional background, and the text itself. -# the text can be enclosed either by '<<..>>' or '@{...}@' +# the text can be enclosed either by '<<..>>' or '@[...]@' RE_PARSE_COLOR_MARKUP = re.compile( r"(?ms)" r"([A-Z_]+(?:\([^\)]+\))?)" # group 0: the coloring r"(?:" r"\<\<(.*?)\>\>|" # group 1: first trap for text <<...>> - r"\@\{(.*?)\}\@" # group 2: second trap for text @{...}@ + r"\@\{(.*?)\}\@|" # group 2: second trap for text @{...}@ + r"\@\[(.*?)\]\@" # group 3: second trap for text @[...]@ ")") From a081f2035ffd7f3149010e5fe5c8b0c51a96a96f Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Sun, 30 Jun 2019 18:04:12 +0300 Subject: [PATCH 10/18] colors/ziplog: swallow BrokenPipeError when parsing from cmdline --- easypy/colors.py | 8 ++++++-- easypy/ziplog.py | 7 +++++-- 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/easypy/colors.py b/easypy/colors.py index b87c8ec4..eea5a20c 100644 --- a/easypy/colors.py +++ b/easypy/colors.py @@ -460,5 +460,9 @@ def register_colorizers(**styles): Colorize lines from stdin """ import fileinput - for line in fileinput.input(openhook=functools.partial(open, errors='replace')): - print(colorize(line), end="", flush=True) + try: + for line in fileinput.input(openhook=functools.partial(open, errors='replace')): + print(colorize(line), end="", flush=True) + except BrokenPipeError: + pass + diff --git a/easypy/ziplog.py b/easypy/ziplog.py index 565187bc..0ecc91e8 100644 --- a/easypy/ziplog.py +++ b/easypy/ziplog.py @@ -122,5 +122,8 @@ def iter_zipped_logs(*log_streams, prefix="DARK_GRAY@{> }@"): if __name__ == "__main__": import sys files = map(open, sys.argv[1:]) - for line in iter_zipped_logs(*files): - print(line, end="") + try: + for line in iter_zipped_logs(*files): + print(line, end="") + except BrokenPipeError: + pass From 52388d397e79f425a9a5898842df5dd37dd60104 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Sun, 30 Jun 2019 18:05:26 +0300 Subject: [PATCH 11/18] regex escaping fixes --- easypy/units.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/easypy/units.py b/easypy/units.py index d1371edf..4e9897a4 100644 --- a/easypy/units.py +++ b/easypy/units.py @@ -18,7 +18,7 @@ class DataSize(int): def __new__(cls, value): if (isinstance(value, str)): - i, u = re.match("(\d*(?:\.\d+)?)?(\w*)", value).groups() + i, u = re.match(r"(\d*(?:\.\d+)?)?(\w*)", value).groups() i = 1 if not i else float(i) if "." in i else int(i) value = i * (cls.NAMED_UNITS[u] if u else 1) if (isinstance(value, cls)): @@ -102,7 +102,7 @@ def randrange(self, divisor, start=None): return random.randrange(start=start, stop=stop) * divisor def __format__(self, spec): - width, precision, name = re.match("(?:(\d+))?(?:\.(\d*))?(\w+)?", spec).groups() + width, precision, name = re.match(r"(?:(\d+))?(?:\.(\d*))?(\w+)?", spec).groups() if name == "d": ret = "{:d}".format(int(self)) elif name == "f": @@ -163,7 +163,7 @@ def __new__(cls, value): try: i, u = float(value), None except ValueError: - i, u = re.match("(\d*(?:\.\d+)?)?(\w*)", value).groups() + i, u = re.match(r"(\d*(?:\.\d+)?)?(\w*)", value).groups() i = 1.0 if not i else float(i) value = i * (cls.NAMED_UNITS[u] if u else 1) if (isinstance(value, cls)): @@ -253,7 +253,7 @@ def __add__(self, other): __radd__ = __add__ def __format__(self, spec): - width, precision, name = re.match("(?:(\d+))?(?:\.(\d*))?(\w+)?", spec).groups() + width, precision, name = re.match(r"(?:(\d+))?(?:\.(\d*))?(\w+)?", spec).groups() if name == "f": return super(Duration, self).__format__(spec) dir = "<" From deb4774011cc57e5edc87479bbf9325b7969f4ed Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Sun, 30 Jun 2019 18:13:14 +0300 Subject: [PATCH 12/18] units: DataSize - return 'byte' and 'MiB' instead of '1 byte' and '1 MiB' this improves compatibility with 3rd party tools that dislike the space inside the value, and is more consistent with higher values ('5bytes', '5MiB') --- CHANGELOG.md | 1 + easypy/units.py | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c53c45fc..7705ec08 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - removed `set_width`, `set_coloring`, `set_graphics` - the env-var `TERM_COLOR_SUPPORT` is no longer checked - the env-var `EASYPY_LOG_INDENTATION` is no longer checked +- DataSize - return 'byte' and 'MiB' instead of '1 byte' and '1 MiB' ### Added - ziplog - added commonly found timestamp patterns diff --git a/easypy/units.py b/easypy/units.py index 4e9897a4..310386d3 100644 --- a/easypy/units.py +++ b/easypy/units.py @@ -119,7 +119,7 @@ def __str__(self): if 0 == self: return '0' if self in self.UNIT_NAMES: - return '1 %s' % (self.UNIT_NAMES[self],) + return self.UNIT_NAMES[self] for unit in self.SORTED_UNITS: name = self.UNIT_NAMES[unit] many = 'bytes' if name == 'byte' else name From a2b18fb29a63eb713cc0c6a38af112dbd18969d9 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Sun, 30 Jun 2019 18:16:18 +0300 Subject: [PATCH 13/18] ziplog: parser for '2018-04-06 17:13:40.955356' --- easypy/ziplog.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/easypy/ziplog.py b/easypy/ziplog.py index 0ecc91e8..72b7b2aa 100644 --- a/easypy/ziplog.py +++ b/easypy/ziplog.py @@ -30,6 +30,10 @@ def to_timestamp(t): (re.compile(r"^(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\+\d{4})"), lambda ts: datetime.strptime(ts, '%Y-%m-%dT%H:%M:%S%z').timestamp()), + # 2018-04-06 17:13:40.955356 + (re.compile(r"^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.(\d{6})"), + lambda ts, ms: time.mktime(time.strptime(ts, "%Y-%m-%d %H:%M:%S")) + float(ms) / 1000000), + # [2018/04/06 17:13:40.955356, (re.compile(r"\[(\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2})\.(\d{6}),"), lambda ts, ms: time.mktime(time.strptime(ts, "%Y/%m/%d %H:%M:%S")) + float(ms) / 1000000), From bc073e83e558150f7700e5423a2faf0915d42138 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Mon, 1 Jul 2019 01:12:23 +0300 Subject: [PATCH 14/18] ziplog: better cli support; show intervals between log lines --- .travis.yml | 4 ++++ easypy/ziplog.py | 48 ++++++++++++++++++++++++++++++++++++++++++------ 2 files changed, 46 insertions(+), 6 deletions(-) diff --git a/.travis.yml b/.travis.yml index 098e415a..e49ec549 100644 --- a/.travis.yml +++ b/.travis.yml @@ -15,6 +15,10 @@ install: - pip install gevent PyYaml - pip install sphinx==1.7.9 ghp-import +before_script: + # we need this for test_ziplog, which parses ambiguous timestamps + - export TZ=Asia/Jerusalem + script: - python -m pytest -vv tests - python -m pytest -vv --doctest-modules easypy diff --git a/easypy/ziplog.py b/easypy/ziplog.py index 72b7b2aa..dfb553ed 100644 --- a/easypy/ziplog.py +++ b/easypy/ziplog.py @@ -92,8 +92,14 @@ def get_timestamp(self, line): return 0 -def iter_zipped_logs(*log_streams, prefix="DARK_GRAY@{> }@"): - "Line iterator that merges lines from different log streams based on their timestamp" +def iter_zipped_logs(*log_streams, prefix="DARK_GRAY@{> }@", show_intervals=None): + """ + Line iterator that merges lines from different log streams based on their timestamp. + Timestamp patterns are found in the TIMESTAMP_GETTERS list in this module. + + :param prefix: Prepend this prefix to each line where a timestamp was identified + :param show_intervals: `s` or `ms` - Prepend the duration since the previous log line + """ # A sorted queue of (timestamp, stream) tuples (lowest-timestamp first) streams = PriorityQueue() @@ -109,9 +115,24 @@ def iter_zipped_logs(*log_streams, prefix="DARK_GRAY@{> }@"): stream_names.append(tstream.name) streams.put(n) + last_ts = None + if show_intervals: + from easypy.units import Duration + + def formatted(line, current_ts, last_ts): + fmt = "{:>7}{}" + if (current_ts and last_ts): + return fmt.format(Duration(current_ts - last_ts).render(show_intervals), line) + else: + return fmt.format("", line) + else: + def formatted(line, current_ts, last_ts): + return line + while not streams.empty(): current_ts, line, stream = streams.get() - yield line + yield formatted(line, current_ts, last_ts) + last_ts = current_ts while True: n = stream.get_next() if not n: @@ -120,14 +141,29 @@ def iter_zipped_logs(*log_streams, prefix="DARK_GRAY@{> }@"): if ts and ts > current_ts: streams.put((ts, line, stream)) break # timestamp advanced - yield line + yield formatted(line, ts, last_ts) + if ts: + last_ts = ts if __name__ == "__main__": import sys - files = map(open, sys.argv[1:]) + import argparse + parser = argparse.ArgumentParser(description='ZipLog - merge logs by timestamps') + parser.add_argument( + 'logs', metavar='N', type=str, nargs='+', + help='log files') + parser.add_argument( + '-i', '--interval', dest='interval', default=None, + help="Show interval by seconds (s), or milliseconds (ms)") + parser.add_argument( + '-p', '--prefix', dest='prefix', default="> ", + help="A prefix to prepend to timestamped lines") + ns = parser.parse_args(sys.argv[1:]) + + files = map(open, ns.logs) try: - for line in iter_zipped_logs(*files): + for line in iter_zipped_logs(*files, show_intervals=ns.interval, prefix=ns.prefix): print(line, end="") except BrokenPipeError: pass From 9d50f4d6f06ca7b0ef714d9de5ad0a02a318f73e Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Mon, 1 Jul 2019 17:24:20 +0300 Subject: [PATCH 15/18] packaging: expose 'colorize' and 'ziplog' as clis --- easypy/colors.py | 5 ++++- easypy/ziplog.py | 6 +++++- setup.py | 6 ++++++ 3 files changed, 15 insertions(+), 2 deletions(-) diff --git a/easypy/colors.py b/easypy/colors.py index eea5a20c..2402b7bc 100644 --- a/easypy/colors.py +++ b/easypy/colors.py @@ -455,7 +455,7 @@ def register_colorizers(**styles): globals().update((name.upper(), Colorizer(color=name, name=name)) for name in COLORS) -if __name__ == '__main__': +def main(): """ Colorize lines from stdin """ @@ -466,3 +466,6 @@ def register_colorizers(**styles): except BrokenPipeError: pass + +if __name__ == "__main__": + main() diff --git a/easypy/ziplog.py b/easypy/ziplog.py index dfb553ed..873d1cf6 100644 --- a/easypy/ziplog.py +++ b/easypy/ziplog.py @@ -146,7 +146,7 @@ def formatted(line, current_ts, last_ts): last_ts = ts -if __name__ == "__main__": +def main(): import sys import argparse parser = argparse.ArgumentParser(description='ZipLog - merge logs by timestamps') @@ -167,3 +167,7 @@ def formatted(line, current_ts, last_ts): print(line, end="") except BrokenPipeError: pass + + +if __name__ == "__main__": + main() diff --git a/setup.py b/setup.py index 841d48f0..24a5c8f9 100755 --- a/setup.py +++ b/setup.py @@ -21,6 +21,12 @@ "License :: OSI Approved :: BSD License", "Operating System :: OS Independent", ], + entry_points={ + 'console_scripts': [ + 'ziplog=easypy.ziplog:main', + 'colorize=easypy.colors:main', + ] + }, ) From cacbbff97efdf508d5e0eda01154b7d5637c16a1 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Mon, 1 Jul 2019 17:25:34 +0300 Subject: [PATCH 16/18] ziplog: yet another timestamp format TODO - allow user customization using a .ziplog file or the likes --- easypy/ziplog.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/easypy/ziplog.py b/easypy/ziplog.py index 873d1cf6..df460936 100644 --- a/easypy/ziplog.py +++ b/easypy/ziplog.py @@ -30,6 +30,10 @@ def to_timestamp(t): (re.compile(r"^(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\+\d{4})"), lambda ts: datetime.strptime(ts, '%Y-%m-%dT%H:%M:%S%z').timestamp()), + # 2018-12-15T02:11:06.123456+02:00 + (re.compile(r"^(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{6})(\+\d{2}):(\d{2})"), + lambda *args: datetime.strptime("{}{}{}".format(*args), '%Y-%m-%dT%H:%M:%S.%f%z').timestamp()), + # 2018-04-06 17:13:40.955356 (re.compile(r"^(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.(\d{6})"), lambda ts, ms: time.mktime(time.strptime(ts, "%Y-%m-%d %H:%M:%S")) + float(ms) / 1000000), From 2e14da5a1f197a85790e3741e9e3b57b795278cb Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Mon, 1 Jul 2019 17:26:27 +0300 Subject: [PATCH 17/18] 0.4.0 - update changlog and setup.py --- CHANGELOG.md | 9 ++++++++- setup.py | 2 +- 2 files changed, 9 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7705ec08..db015593 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +## [0.4.0] + ### Changed - Logging Initialization - a run-once `initialize` method takes care of it all @@ -15,7 +17,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - DataSize - return 'byte' and 'MiB' instead of '1 byte' and '1 MiB' ### Added -- ziplog - added commonly found timestamp patterns +- ziplog + - expose as a cli tool - `ziplog` + - added commonly found timestamp patterns +- colors + - expose as a cli tool - `colorize +- random: added `perchance(probabilty)` - Examples - a skeleton for initializing logging with easypy diff --git a/setup.py b/setup.py index 24a5c8f9..0454ba60 100755 --- a/setup.py +++ b/setup.py @@ -7,7 +7,7 @@ setuptools.setup( name='weka-easypy', - version='0.3.0', + version='0.4.0', description='easypy is a collection of python modules that makes developers happy', author='Ofer Koren', author_email='koreno@gmail.com', From 0a5a83e24be0a436d0298c93834b8ccde0a731a5 Mon Sep 17 00:00:00 2001 From: Ofer Koren Date: Mon, 1 Jul 2019 17:29:36 +0300 Subject: [PATCH 18/18] tests: fix to use unittest.mock instead of mock package --- easypy/concurrency.py | 1 + tests/test_concurrency.py | 2 +- tests/test_sync.py | 3 +-- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/easypy/concurrency.py b/easypy/concurrency.py index 2dcccdbc..5055d7b0 100644 --- a/easypy/concurrency.py +++ b/easypy/concurrency.py @@ -76,6 +76,7 @@ import os from collections import namedtuple from datetime import datetime +from unittest.mock import MagicMock import easypy._multithreading_init # noqa; make it initialize the threads tree from easypy.exceptions import PException diff --git a/tests/test_concurrency.py b/tests/test_concurrency.py index 24f6f0bc..96e13079 100644 --- a/tests/test_concurrency.py +++ b/tests/test_concurrency.py @@ -1,4 +1,4 @@ -from mock import patch, call +from unittest.mock import patch import pytest from time import sleep diff --git a/tests/test_sync.py b/tests/test_sync.py index ab48d36f..de0a3631 100644 --- a/tests/test_sync.py +++ b/tests/test_sync.py @@ -1,4 +1,4 @@ -from mock import patch, call +from unittest.mock import patch, call import pytest from time import sleep import threading @@ -10,7 +10,6 @@ from easypy.timing import repeat, timing from easypy.bunch import Bunch from easypy.units import Duration -from easypy.resilience import retrying from easypy.sync import iter_wait, wait, iter_wait_progress, Timer, TimeoutException, PredicateNotSatisfied from easypy.sync import SynchronizationCoordinator, SYNC