From 57d994422d69e41f9be716085824bc6464e27f9b Mon Sep 17 00:00:00 2001 From: ed Date: Sat, 6 Mar 2021 17:38:56 +0100 Subject: [PATCH] logging cleanup --- copyparty/authsrv.py | 18 +++++++++--------- copyparty/broker_mpw.py | 10 +++++----- copyparty/broker_thr.py | 2 +- copyparty/httpcli.py | 6 +++--- copyparty/httpconn.py | 8 ++++---- copyparty/httpsrv.py | 9 +++++---- copyparty/mtag.py | 18 ++++++++---------- copyparty/svchub.py | 11 +++++++++-- copyparty/tcpsrv.py | 7 ++++--- copyparty/u2idx.py | 4 ++-- copyparty/up2k.py | 25 +++++++++++++------------ copyparty/util.py | 28 +++++++++++++++++----------- 12 files changed, 80 insertions(+), 66 deletions(-) diff --git a/copyparty/authsrv.py b/copyparty/authsrv.py index 3cb44a68..c4cc0c67 100644 --- a/copyparty/authsrv.py +++ b/copyparty/authsrv.py @@ -6,7 +6,7 @@ import re import threading from .__init__ import PY2, WINDOWS -from .util import undot, Pebkac, fsdec, fsenc, statdir +from .util import undot, Pebkac, fsdec, fsenc, statdir, uprint class VFS(object): @@ -106,7 +106,7 @@ class VFS(object): """return user-readable [fsdir,real,virt] items at vpath""" virt_vis = {} # nodes readable by user abspath = self.canonical(rem) - real = list(statdir(print, scandir, lstat, abspath)) + real = list(statdir(uprint, scandir, lstat, abspath)) real.sort() if not rem: for name, vn2 in sorted(self.nodes.items()): @@ -147,8 +147,8 @@ class AuthSrv(object): self.mutex = threading.Lock() self.reload() - def log(self, msg): - self.log_func("auth", msg) + def log(self, msg, c=0): + self.log_func("auth", msg, c) def invert(self, orig): if PY2: @@ -304,9 +304,9 @@ class AuthSrv(object): if missing_users: self.log( - "\033[31myou must -a the following users: " - + ", ".join(k for k in sorted(missing_users)) - + "\033[0m" + "you must -a the following users: " + + ", ".join(k for k in sorted(missing_users)), + c=1, ) raise Exception("invalid config") @@ -329,8 +329,8 @@ class AuthSrv(object): v, _ = vfs.get("/", "*", False, True) if self.warn_anonwrite and os.getcwd() == v.realpath: self.warn_anonwrite = False - msg = "\033[31manyone can read/write the current directory: {}\033[0m" - self.log(msg.format(v.realpath)) + msg = "anyone can read/write the current directory: {}" + self.log(msg.format(v.realpath), c=1) except Pebkac: self.warn_anonwrite = True diff --git a/copyparty/broker_mpw.py b/copyparty/broker_mpw.py index b1a5abd3..bd1fb486 100644 --- a/copyparty/broker_mpw.py +++ b/copyparty/broker_mpw.py @@ -49,11 +49,11 @@ class MpWorker(object): # print('k') pass - def log(self, src, msg): - self.q_yield.put([0, "log", [src, msg]]) + def log(self, src, msg, c=0): + self.q_yield.put([0, "log", [src, msg, c]]) - def logw(self, msg): - self.log("mp{}".format(self.n), msg) + def logw(self, msg, c=0): + self.log("mp{}".format(self.n), msg, c) def httpdrop(self, addr): self.q_yield.put([0, "httpdrop", [addr]]) @@ -73,7 +73,7 @@ class MpWorker(object): if PY2: sck = pickle.loads(sck) # nosec - self.log("%s %s" % addr, "\033[1;30m|%sC-qpop\033[0m" % ("-" * 4,)) + self.log("%s %s" % addr, "|%sC-qpop" % ("-" * 4,), c="1;30") self.httpsrv.accept(sck, addr) with self.mutex: diff --git a/copyparty/broker_thr.py b/copyparty/broker_thr.py index b9d107f8..121da451 100644 --- a/copyparty/broker_thr.py +++ b/copyparty/broker_thr.py @@ -28,7 +28,7 @@ class BrokerThr(object): def put(self, want_retval, dest, *args): if dest == "httpconn": sck, addr = args - self.log("%s %s" % addr, "\033[1;30m|%sC-qpop\033[0m" % ("-" * 4,)) + self.log("%s %s" % addr, "|%sC-qpop" % ("-" * 4,), c="1;30") self.httpsrv.accept(sck, addr) else: diff --git a/copyparty/httpcli.py b/copyparty/httpcli.py index 5e0a1396..1f903da3 100644 --- a/copyparty/httpcli.py +++ b/copyparty/httpcli.py @@ -41,8 +41,8 @@ class HttpCli(object): self.absolute_urls = False self.out_headers = {"Access-Control-Allow-Origin": "*"} - def log(self, msg): - self.log_func(self.log_src, msg) + def log(self, msg, c=0): + self.log_func(self.log_src, msg, c) def _check_nonfatal(self, ex): return ex.code < 400 or ex.code == 404 @@ -63,7 +63,7 @@ class HttpCli(object): if not headerlines[0]: # seen after login with IE6.0.2900.5512.xpsp.080413-2111 (xp-sp3) - self.log("\033[1;31mBUG: trailing newline from previous request\033[0m") + self.log("BUG: trailing newline from previous request", c="1;31") headerlines.pop(0) try: diff --git a/copyparty/httpconn.py b/copyparty/httpconn.py index cb808e0e..95c9595b 100644 --- a/copyparty/httpconn.py +++ b/copyparty/httpconn.py @@ -81,8 +81,8 @@ class HttpConn(object): def respath(self, res_name): return os.path.join(E.mod, "web", res_name) - def log(self, msg): - self.log_func(self.log_src, msg) + def log(self, msg, c=0): + self.log_func(self.log_src, msg, c) def get_u2idx(self): if not self.u2idx: @@ -129,7 +129,7 @@ class HttpConn(object): if is_https: if self.sr: - self.log("\033[1;31mTODO: cannot do https in jython\033[0m") + self.log("TODO: cannot do https in jython", c="1;31") return self.log_src = self.log_src.replace("[36m", "[35m") @@ -180,7 +180,7 @@ class HttpConn(object): pass else: - self.log("\033[35mhandshake\033[0m " + em) + self.log("handshake\033[0m " + em, c=5) return diff --git a/copyparty/httpsrv.py b/copyparty/httpsrv.py index a6e58255..8360bf57 100644 --- a/copyparty/httpsrv.py +++ b/copyparty/httpsrv.py @@ -38,7 +38,7 @@ class HttpSrv(object): def accept(self, sck, addr): """takes an incoming tcp connection and creates a thread to handle it""" - self.log("%s %s" % addr, "\033[1;30m|%sC-cthr\033[0m" % ("-" * 5,)) + self.log("%s %s" % addr, "|%sC-cthr" % ("-" * 5,), c="1;30") thr = threading.Thread(target=self.thr_client, args=(sck, addr)) thr.daemon = True thr.start() @@ -66,11 +66,11 @@ class HttpSrv(object): thr.start() try: - self.log("%s %s" % addr, "\033[1;30m|%sC-crun\033[0m" % ("-" * 6,)) + self.log("%s %s" % addr, "|%sC-crun" % ("-" * 6,), c="1;30") cli.run() finally: - self.log("%s %s" % addr, "\033[1;30m|%sC-cdone\033[0m" % ("-" * 7,)) + self.log("%s %s" % addr, "|%sC-cdone" % ("-" * 7,), c="1;30") try: sck.shutdown(socket.SHUT_RDWR) sck.close() @@ -78,7 +78,8 @@ class HttpSrv(object): if not MACOS: self.log( "%s %s" % addr, - "\033[1;30mshut({}): {}\033[0m".format(sck.fileno(), ex), + "shut({}): {}".format(sck.fileno(), ex), + c="1;30", ) if ex.errno not in [10038, 10054, 107, 57, 9]: # 10038 No longer considered a socket diff --git a/copyparty/mtag.py b/copyparty/mtag.py index 2454bd29..dab53f2c 100644 --- a/copyparty/mtag.py +++ b/copyparty/mtag.py @@ -28,7 +28,7 @@ class MTag(object): try: import mutagen except: - self.log("\033[33mcould not load mutagen, trying ffprobe instead") + self.log("could not load mutagen, trying ffprobe instead", c=3) self.backend = "ffprobe" if self.backend == "ffprobe": @@ -48,12 +48,12 @@ class MTag(object): if self.usable and WINDOWS and sys.version_info < (3, 8): self.usable = False or_ffprobe = " or python >= 3.8" - msg = "\033[31mfound ffprobe but your python is too old; need 3.8 or newer" - self.log(msg) + msg = "found ffprobe but your python is too old; need 3.8 or newer" + self.log(msg, c=1) if not self.usable: - msg = "\033[31mneed mutagen{} to read media tags so please run this:\n {} -m pip install --user mutagen \033[0m" - self.log(msg.format(or_ffprobe, os.path.basename(sys.executable))) + msg = "need mutagen{} to read media tags so please run this:\n {} -m pip install --user mutagen" + self.log(msg.format(or_ffprobe, os.path.basename(sys.executable)), c=1) return # https://picard-docs.musicbrainz.org/downloads/MusicBrainz_Picard_Tag_Map.html @@ -125,8 +125,8 @@ class MTag(object): } # self.get = self.compare - def log(self, msg): - self.log_func("mtag", msg) + def log(self, msg, c=0): + self.log_func("mtag", msg, c) def normalize_tags(self, ret, md): for k, v in dict(md).items(): @@ -295,9 +295,7 @@ class MTag(object): sec *= 60 sec += int(f) except: - self.log( - "\033[33minvalid timestr from ffmpeg: [{}]".format(tstr) - ) + self.log("invalid timestr from ffmpeg: [{}]".format(tstr), c=3) ret[".dur"] = sec m = ptn_br1.search(ln) diff --git a/copyparty/svchub.py b/copyparty/svchub.py index 8983d423..80f7d627 100644 --- a/copyparty/svchub.py +++ b/copyparty/svchub.py @@ -65,10 +65,10 @@ class SvcHub(object): self.broker.shutdown() print("nailed it") - def _log_disabled(self, src, msg): + def _log_disabled(self, src, msg, c=0): pass - def _log_enabled(self, src, msg): + def _log_enabled(self, src, msg, c=0): """handles logging from all components""" with self.log_mutex: now = time.time() @@ -91,6 +91,13 @@ class SvcHub(object): msg = self.ansi_re.sub("", msg) if "\033" in src: src = self.ansi_re.sub("", src) + elif c: + if isinstance(c, int): + msg = "\033[3{}m{}".format(c, msg) + elif "\033" not in c: + msg = "\033[{}m{}\033[0m".format(c, msg) + else: + msg = "{}{}\033[0m".format(c, msg) ts = datetime.utcfromtimestamp(now).strftime("%H:%M:%S.%f")[:-3] msg = fmt.format(ts, src, msg) diff --git a/copyparty/tcpsrv.py b/copyparty/tcpsrv.py index 71c8997c..e0e31409 100644 --- a/copyparty/tcpsrv.py +++ b/copyparty/tcpsrv.py @@ -68,21 +68,22 @@ class TcpSrv(object): self.log("tcpsrv", "listening @ {0}:{1}".format(ip, port)) while True: - self.log("tcpsrv", "\033[1;30m|%sC-ncli\033[0m" % ("-" * 1,)) + self.log("tcpsrv", "|%sC-ncli" % ("-" * 1,), c="1;30") if self.num_clients.v >= self.args.nc: time.sleep(0.1) continue - self.log("tcpsrv", "\033[1;30m|%sC-acc1\033[0m" % ("-" * 2,)) + self.log("tcpsrv", "|%sC-acc1" % ("-" * 2,), c="1;30") ready, _, _ = select.select(self.srv, [], []) for srv in ready: sck, addr = srv.accept() sip, sport = srv.getsockname() self.log( "%s %s" % addr, - "\033[1;30m|{}C-acc2 \033[0;36m{} \033[3{}m{}".format( + "|{}C-acc2 \033[0;36m{} \033[3{}m{}".format( "-" * 3, sip, sport % 8, sport ), + c="1;30", ) self.num_clients.add() self.hub.broker.put(False, "httpconn", sck, addr) diff --git a/copyparty/u2idx.py b/copyparty/u2idx.py index 84918d04..c94a0dd3 100644 --- a/copyparty/u2idx.py +++ b/copyparty/u2idx.py @@ -26,8 +26,8 @@ class U2idx(object): self.cur = {} - def log(self, msg): - self.log_func("u2idx", msg) + def log(self, msg, c=0): + self.log_func("u2idx", msg, c) def fsearch(self, vols, body): """search by up2k hashlist""" diff --git a/copyparty/up2k.py b/copyparty/up2k.py index 86a90668..0c1349cb 100644 --- a/copyparty/up2k.py +++ b/copyparty/up2k.py @@ -91,7 +91,7 @@ class Up2k(object): self.log("could not initialize sqlite3, will use in-memory registry only") # this is kinda jank - auth = AuthSrv(self.args, self.log, False) + auth = AuthSrv(self.args, self.log_func, False) have_e2d = self.init_indexes(auth) if have_e2d: @@ -107,8 +107,8 @@ class Up2k(object): thr.daemon = True thr.start() - def log(self, msg): - self.log_func("up2k", msg + "\033[K") + def log(self, msg, c=0): + self.log_func("up2k", msg + "\033[K", c) def w8enc(self, rd, fn): ret = [] @@ -170,8 +170,8 @@ class Up2k(object): modified = True if modified: - msg = "\033[33mdisabling -e2t because your sqlite belongs in a museum" - self.log(msg) + msg = "disabling -e2t because your sqlite belongs in a museum" + self.log(msg, c=3) live_vols = [] for vol in vols: @@ -179,7 +179,7 @@ class Up2k(object): os.listdir(vol.realpath) live_vols.append(vol) except: - self.log("\033[31mcannot access " + vol.realpath) + self.log("cannot access " + vol.realpath, c=1) vols = live_vols @@ -230,8 +230,8 @@ class Up2k(object): self.log(msg.format(len(vols), time.time() - t0)) if needed_mutagen: - msg = "\033[31mcould not read tags because no backends are available (mutagen or ffprobe)\033[0m" - self.log(msg) + msg = "could not read tags because no backends are available (mutagen or ffprobe)" + self.log(msg, c=1) return have_e2d @@ -526,8 +526,9 @@ class Up2k(object): n = self._tag_file(write_cur, entags, wark, abspath, tags) self.n_mtag_tags_added += n except: - msg = "\033[33m{} failed to read tags from {}:\n{}" - self.log(msg.format(self.mtag.backend, abspath, traceback.format_exc())) + ex = traceback.format_exc() + msg = "{} failed to read tags from {}:\n{}" + self.log(msg.format(self.mtag.backend, abspath, ex), c=3) q.task_done() @@ -1071,12 +1072,12 @@ class Up2k(object): with self.mutex: cur = self.cur[ptop] if not cur: - self.log("\033[31mno cursor to write tags with??") + self.log("no cursor to write tags with??", c=1) continue entags = self.entags[ptop] if not entags: - self.log("\033[33mno entags okay.jpg") + self.log("no entags okay.jpg", c=3) continue if "e2t" in self.flags[ptop]: diff --git a/copyparty/util.py b/copyparty/util.py index 37d71718..041ed32c 100644 --- a/copyparty/util.py +++ b/copyparty/util.py @@ -119,19 +119,22 @@ class ProgressPrinter(threading.Thread): continue msg = self.msg - m = " {}\033[K\r".format(msg) - try: - print(m, end="") - except UnicodeEncodeError: - try: - print(m.encode("utf-8", "replace").decode(), end="") - except: - print(m.encode("ascii", "replace").decode(), end="") + uprint(" {}\033[K\r".format(msg)) print("\033[K", end="") sys.stdout.flush() # necessary on win10 even w/ stderr btw +def uprint(msg): + try: + print(msg, end="") + except UnicodeEncodeError: + try: + print(msg.encode("utf-8", "replace").decode(), end="") + except: + print(msg.encode("ascii", "replace").decode(), end="") + + @contextlib.contextmanager def ren_open(fname, *args, **kwargs): fdir = kwargs.pop("fdir", None) @@ -734,7 +737,8 @@ def statdir(logger, scandir, lstat, top): try: yield [fsdec(fh.name), fh.stat(follow_symlinks=not lstat)] except Exception as ex: - logger("scan-stat: {} @ {}".format(repr(ex), fsdec(fh.path))) + msg = "scan-stat: \033[36m{} @ {}" + logger(msg.format(repr(ex), fsdec(fh.path))) else: src = "listdir" fun = os.lstat if lstat else os.stat @@ -743,9 +747,11 @@ def statdir(logger, scandir, lstat, top): try: yield [fsdec(name), fun(abspath)] except Exception as ex: - logger("list-stat: {} @ {}".format(repr(ex), fsdec(abspath))) + msg = "list-stat: \033[36m{} @ {}" + logger(msg.format(repr(ex), fsdec(abspath))) + except Exception as ex: - logger("{}: {} @ {}".format(src, repr(ex), top)) + logger("{}: \033[31m{} @ {}".format(src, repr(ex), top)) def unescape_cookie(orig):