add logging to file

This commit is contained in:
ed 2021-07-05 23:30:33 +02:00
parent 1e27a4c2df
commit 2f85c1fb18
10 changed files with 119 additions and 56 deletions

View file

@ -9,6 +9,9 @@ import os
PY2 = sys.version_info[0] == 2 PY2 = sys.version_info[0] == 2
if PY2: if PY2:
sys.dont_write_bytecode = True sys.dont_write_bytecode = True
unicode = unicode
else:
unicode = str
WINDOWS = False WINDOWS = False
if platform.system() == "Windows": if platform.system() == "Windows":

View file

@ -20,7 +20,7 @@ import threading
import traceback import traceback
from textwrap import dedent from textwrap import dedent
from .__init__ import E, WINDOWS, VT100, PY2 from .__init__ import E, WINDOWS, VT100, PY2, unicode
from .__version__ import S_VERSION, S_BUILD_DT, CODENAME from .__version__ import S_VERSION, S_BUILD_DT, CODENAME
from .svchub import SvcHub from .svchub import SvcHub
from .util import py_desc, align_tab, IMPLICATIONS, alltrace from .util import py_desc, align_tab, IMPLICATIONS, alltrace
@ -31,6 +31,8 @@ try:
except: except:
HAVE_SSL = False HAVE_SSL = False
printed = ""
class RiceFormatter(argparse.HelpFormatter): class RiceFormatter(argparse.HelpFormatter):
def _get_help_string(self, action): def _get_help_string(self, action):
@ -61,8 +63,15 @@ class Dodge11874(RiceFormatter):
super(Dodge11874, self).__init__(*args, **kwargs) super(Dodge11874, self).__init__(*args, **kwargs)
def lprint(*a, **ka):
global printed
printed += " ".join(unicode(x) for x in a) + ka.get("end", "\n")
print(*a, **ka)
def warn(msg): def warn(msg):
print("\033[1mwarning:\033[0;33m {}\033[0m\n".format(msg)) lprint("\033[1mwarning:\033[0;33m {}\033[0m\n".format(msg))
def ensure_locale(): def ensure_locale():
@ -73,7 +82,7 @@ def ensure_locale():
]: ]:
try: try:
locale.setlocale(locale.LC_ALL, x) locale.setlocale(locale.LC_ALL, x)
print("Locale:", x) lprint("Locale:", x)
break break
except: except:
continue continue
@ -94,7 +103,7 @@ def ensure_cert():
try: try:
if filecmp.cmp(cert_cfg, cert_insec): if filecmp.cmp(cert_cfg, cert_insec):
print( lprint(
"\033[33m using default TLS certificate; https will be insecure." "\033[33m using default TLS certificate; https will be insecure."
+ "\033[36m\n certificate location: {}\033[0m\n".format(cert_cfg) + "\033[36m\n certificate location: {}\033[0m\n".format(cert_cfg)
) )
@ -123,7 +132,7 @@ def configure_ssl_ver(al):
if "help" in sslver: if "help" in sslver:
avail = [terse_sslver(x[6:]) for x in flags] avail = [terse_sslver(x[6:]) for x in flags]
avail = " ".join(sorted(avail) + ["all"]) avail = " ".join(sorted(avail) + ["all"])
print("\navailable ssl/tls versions:\n " + avail) lprint("\navailable ssl/tls versions:\n " + avail)
sys.exit(0) sys.exit(0)
al.ssl_flags_en = 0 al.ssl_flags_en = 0
@ -143,7 +152,7 @@ def configure_ssl_ver(al):
for k in ["ssl_flags_en", "ssl_flags_de"]: for k in ["ssl_flags_en", "ssl_flags_de"]:
num = getattr(al, k) num = getattr(al, k)
print("{}: {:8x} ({})".format(k, num, num)) lprint("{}: {:8x} ({})".format(k, num, num))
# think i need that beer now # think i need that beer now
@ -160,13 +169,13 @@ def configure_ssl_ciphers(al):
try: try:
ctx.set_ciphers(al.ciphers) ctx.set_ciphers(al.ciphers)
except: except:
print("\n\033[1;31mfailed to set ciphers\033[0m\n") lprint("\n\033[1;31mfailed to set ciphers\033[0m\n")
if not hasattr(ctx, "get_ciphers"): if not hasattr(ctx, "get_ciphers"):
print("cannot read cipher list: openssl or python too old") lprint("cannot read cipher list: openssl or python too old")
else: else:
ciphers = [x["description"] for x in ctx.get_ciphers()] ciphers = [x["description"] for x in ctx.get_ciphers()]
print("\n ".join(["\nenabled ciphers:"] + align_tab(ciphers) + [""])) lprint("\n ".join(["\nenabled ciphers:"] + align_tab(ciphers) + [""]))
if is_help: if is_help:
sys.exit(0) sys.exit(0)
@ -249,17 +258,18 @@ def run_argparse(argv, formatter):
), ),
) )
# fmt: off # fmt: off
ap.add_argument("-c", metavar="PATH", type=str, action="append", help="add config file") ap2 = ap.add_argument_group('general options')
ap.add_argument("-nc", metavar="NUM", type=int, default=64, help="max num clients") ap2.add_argument("-c", metavar="PATH", type=str, action="append", help="add config file")
ap.add_argument("-j", metavar="CORES", type=int, default=1, help="max num cpu cores") ap2.add_argument("-nc", metavar="NUM", type=int, default=64, help="max num clients")
ap.add_argument("-a", metavar="ACCT", type=str, action="append", help="add account, USER:PASS; example [ed:wark") ap2.add_argument("-j", metavar="CORES", type=int, default=1, help="max num cpu cores")
ap.add_argument("-v", metavar="VOL", type=str, action="append", help="add volume, SRC:DST:FLAG; example [.::r], [/mnt/nas/music:/music:r:aed") ap2.add_argument("-a", metavar="ACCT", type=str, action="append", help="add account, USER:PASS; example [ed:wark")
ap.add_argument("-ed", action="store_true", help="enable ?dots") ap2.add_argument("-v", metavar="VOL", type=str, action="append", help="add volume, SRC:DST:FLAG; example [.::r], [/mnt/nas/music:/music:r:aed")
ap.add_argument("-emp", action="store_true", help="enable markdown plugins") ap2.add_argument("-ed", action="store_true", help="enable ?dots")
ap.add_argument("-mcr", metavar="SEC", type=int, default=60, help="md-editor mod-chk rate") ap2.add_argument("-emp", action="store_true", help="enable markdown plugins")
ap.add_argument("--dotpart", action="store_true", help="dotfile incomplete uploads") ap2.add_argument("-mcr", metavar="SEC", type=int, default=60, help="md-editor mod-chk rate")
ap.add_argument("--sparse", metavar="MiB", type=int, default=4, help="up2k min.size threshold (mswin-only)") ap2.add_argument("--dotpart", action="store_true", help="dotfile incomplete uploads")
ap.add_argument("--urlform", metavar="MODE", type=str, default="print,get", help="how to handle url-forms; examples: [stash], [save,get]") ap2.add_argument("--sparse", metavar="MiB", type=int, default=4, help="up2k min.size threshold (mswin-only)")
ap2.add_argument("--urlform", metavar="MODE", type=str, default="print,get", help="how to handle url-forms; examples: [stash], [save,get]")
ap2 = ap.add_argument_group('network options') ap2 = ap.add_argument_group('network options')
ap2.add_argument("-i", metavar="IP", type=str, default="0.0.0.0", help="ip to bind (comma-sep.)") ap2.add_argument("-i", metavar="IP", type=str, default="0.0.0.0", help="ip to bind (comma-sep.)")
@ -286,6 +296,7 @@ def run_argparse(argv, formatter):
ap2 = ap.add_argument_group('logging options') ap2 = ap.add_argument_group('logging options')
ap2.add_argument("-q", action="store_true", help="quiet") ap2.add_argument("-q", action="store_true", help="quiet")
ap2.add_argument("-lo", metavar="PATH", type=str, help="logfile, example: cpp-%%Y-%%m%%d-%%H%%M%%S.txt.xz")
ap2.add_argument("--log-conn", action="store_true", help="print tcp-server msgs") ap2.add_argument("--log-conn", action="store_true", help="print tcp-server msgs")
ap2.add_argument("--ihead", metavar="HEADER", action='append', help="dump incoming header") ap2.add_argument("--ihead", metavar="HEADER", action='append', help="dump incoming header")
ap2.add_argument("--lf-url", metavar="RE", type=str, default=r"^/\.cpr/|\?th=[wj]$", help="dont log URLs matching") ap2.add_argument("--lf-url", metavar="RE", type=str, default=r"^/\.cpr/|\?th=[wj]$", help="dont log URLs matching")
@ -348,7 +359,7 @@ def main(argv=None):
desc = py_desc().replace("[", "\033[1;30m[") desc = py_desc().replace("[", "\033[1;30m[")
f = '\033[36mcopyparty v{} "\033[35m{}\033[36m" ({})\n{}\033[0m\n' f = '\033[36mcopyparty v{} "\033[35m{}\033[36m" ({})\n{}\033[0m\n'
print(f.format(S_VERSION, CODENAME, S_BUILD_DT, desc)) lprint(f.format(S_VERSION, CODENAME, S_BUILD_DT, desc))
ensure_locale() ensure_locale()
if HAVE_SSL: if HAVE_SSL:
@ -362,7 +373,7 @@ def main(argv=None):
continue continue
msg = "\033[1;31mWARNING:\033[0;1m\n {} \033[0;33mwas replaced with\033[0;1m {} \033[0;33mand will be removed\n\033[0m" msg = "\033[1;31mWARNING:\033[0;1m\n {} \033[0;33mwas replaced with\033[0;1m {} \033[0;33mand will be removed\n\033[0m"
print(msg.format(dk, nk)) lprint(msg.format(dk, nk))
argv[idx] = nk argv[idx] = nk
time.sleep(2) time.sleep(2)
@ -416,7 +427,7 @@ def main(argv=None):
# signal.signal(signal.SIGINT, sighandler) # signal.signal(signal.SIGINT, sighandler)
SvcHub(al).run() SvcHub(al, argv, printed).run()
if __name__ == "__main__": if __name__ == "__main__":

View file

@ -10,13 +10,14 @@ import hashlib
import threading import threading
from .__init__ import WINDOWS from .__init__ import WINDOWS
from .util import IMPLICATIONS, uncyg, undot, Pebkac, fsdec, fsenc, statdir, nuprint from .util import IMPLICATIONS, uncyg, undot, Pebkac, fsdec, fsenc, statdir
class VFS(object): class VFS(object):
"""single level in the virtual fs""" """single level in the virtual fs"""
def __init__(self, realpath, vpath, uread=[], uwrite=[], uadm=[], flags={}): def __init__(self, log, realpath, vpath, uread=[], uwrite=[], uadm=[], flags={}):
self.log = log
self.realpath = realpath # absolute path on host filesystem self.realpath = realpath # absolute path on host filesystem
self.vpath = vpath # absolute path in the virtual filesystem self.vpath = vpath # absolute path in the virtual filesystem
self.uread = uread # users who can read this self.uread = uread # users who can read this
@ -62,6 +63,7 @@ class VFS(object):
return self.nodes[name].add(src, dst) return self.nodes[name].add(src, dst)
vn = VFS( vn = VFS(
self.log,
os.path.join(self.realpath, name) if self.realpath else None, os.path.join(self.realpath, name) if self.realpath else None,
"{}/{}".format(self.vpath, name).lstrip("/"), "{}/{}".format(self.vpath, name).lstrip("/"),
self.uread, self.uread,
@ -79,7 +81,7 @@ class VFS(object):
# leaf does not exist; create and keep permissions blank # leaf does not exist; create and keep permissions blank
vp = "{}/{}".format(self.vpath, dst).lstrip("/") vp = "{}/{}".format(self.vpath, dst).lstrip("/")
vn = VFS(src, vp) vn = VFS(self.log, src, vp)
vn.dbv = self.dbv or self vn.dbv = self.dbv or self
self.nodes[dst] = vn self.nodes[dst] = vn
return vn return vn
@ -181,7 +183,7 @@ class VFS(object):
"""return user-readable [fsdir,real,virt] items at vpath""" """return user-readable [fsdir,real,virt] items at vpath"""
virt_vis = {} # nodes readable by user virt_vis = {} # nodes readable by user
abspath = self.canonical(rem) abspath = self.canonical(rem)
real = list(statdir(nuprint, scandir, lstat, abspath)) real = list(statdir(self.log, scandir, lstat, abspath))
real.sort() real.sort()
if not rem: if not rem:
for name, vn2 in sorted(self.nodes.items()): for name, vn2 in sorted(self.nodes.items()):
@ -209,7 +211,10 @@ class VFS(object):
) )
if seen and not fsroot.startswith(seen[-1]) and fsroot in seen: if seen and not fsroot.startswith(seen[-1]) and fsroot in seen:
print("bailing from symlink loop,\n {}\n {}".format(seen[-1], fsroot)) self.log(
"vfs.walk",
"bailing from symlink loop,\n {}\n {}".format(seen[-1], fsroot),
)
return return
seen = seen[:] + [fsroot] seen = seen[:] + [fsroot]
@ -474,7 +479,7 @@ class AuthSrv(object):
) )
except: except:
m = "\n\033[1;31m\nerror in config file {} on line {}:\n\033[0m" m = "\n\033[1;31m\nerror in config file {} on line {}:\n\033[0m"
print(m.format(cfg_fn, self.line_ctr)) self.log(m.format(cfg_fn, self.line_ctr), 1)
raise raise
# case-insensitive; normalize # case-insensitive; normalize
@ -490,10 +495,10 @@ class AuthSrv(object):
if not mount: if not mount:
# -h says our defaults are CWD at root and read/write for everyone # -h says our defaults are CWD at root and read/write for everyone
vfs = VFS(os.path.abspath("."), "", ["*"], ["*"]) vfs = VFS(self.log_func, os.path.abspath("."), "", ["*"], ["*"])
elif "" not in mount: elif "" not in mount:
# there's volumes but no root; make root inaccessible # there's volumes but no root; make root inaccessible
vfs = VFS(None, "") vfs = VFS(self.log_func, None, "")
vfs.flags["d2d"] = True vfs.flags["d2d"] = True
maxdepth = 0 maxdepth = 0
@ -505,7 +510,13 @@ class AuthSrv(object):
if dst == "": if dst == "":
# rootfs was mapped; fully replaces the default CWD vfs # rootfs was mapped; fully replaces the default CWD vfs
vfs = VFS( vfs = VFS(
mount[dst], dst, mread[dst], mwrite[dst], madm[dst], mflags[dst] self.log_func,
mount[dst],
dst,
mread[dst],
mwrite[dst],
madm[dst],
mflags[dst],
) )
continue continue
@ -788,7 +799,7 @@ class AuthSrv(object):
msg = [x[1] for x in files] msg = [x[1] for x in files]
if msg: if msg:
nuprint("\n".join(msg)) self.log("\n" + "\n".join(msg))
if n_bads and flag_p: if n_bads and flag_p:
raise Exception("found symlink leaving volume, and strict is set") raise Exception("found symlink leaving volume, and strict is set")

View file

@ -13,15 +13,12 @@ import ctypes
from datetime import datetime from datetime import datetime
import calendar import calendar
from .__init__ import E, PY2, WINDOWS, ANYWIN from .__init__ import E, PY2, WINDOWS, ANYWIN, unicode
from .util import * # noqa # pylint: disable=unused-wildcard-import from .util import * # noqa # pylint: disable=unused-wildcard-import
from .authsrv import AuthSrv from .authsrv import AuthSrv
from .szip import StreamZip from .szip import StreamZip
from .star import StreamTar from .star import StreamTar
if not PY2:
unicode = str
NO_CACHE = {"Cache-Control": "no-cache"} NO_CACHE = {"Cache-Control": "no-cache"}
NO_STORE = {"Cache-Control": "no-store; max-age=0"} NO_STORE = {"Cache-Control": "no-store; max-age=0"}

View file

@ -7,12 +7,9 @@ import json
import shutil import shutil
import subprocess as sp import subprocess as sp
from .__init__ import PY2, WINDOWS from .__init__ import PY2, WINDOWS, unicode
from .util import fsenc, fsdec, uncyg, REKOBO_LKEY from .util import fsenc, fsdec, uncyg, REKOBO_LKEY
if not PY2:
unicode = str
def have_ff(cmd): def have_ff(cmd):
if PY2: if PY2:

View file

@ -5,6 +5,7 @@ import re
import os import os
import sys import sys
import time import time
import shlex
import threading import threading
from datetime import datetime, timedelta from datetime import datetime, timedelta
import calendar import calendar
@ -28,7 +29,7 @@ class SvcHub(object):
put() can return a queue (if want_reply=True) which has a blocking get() with the response. put() can return a queue (if want_reply=True) which has a blocking get() with the response.
""" """
def __init__(self, args): def __init__(self, args, argv, printed):
self.args = args self.args = args
self.ansi_re = re.compile("\033\\[[^m]*m") self.ansi_re = re.compile("\033\\[[^m]*m")
@ -36,6 +37,7 @@ class SvcHub(object):
self.next_day = 0 self.next_day = 0
self.log = self._log_disabled if args.q else self._log_enabled self.log = self._log_disabled if args.q else self._log_enabled
self.logf = self._setup_logfile(argv, printed) if args.lo else None
# initiate all services to manage # initiate all services to manage
self.asrv = AuthSrv(self.args, self.log, False) self.asrv = AuthSrv(self.args, self.log, False)
@ -69,6 +71,33 @@ class SvcHub(object):
self.broker = Broker(self) self.broker = Broker(self)
def _setup_logfile(self, argv, printed):
dt = datetime.utcfromtimestamp(time.time())
fn = self.args.lo
for fs in "YmdHMS":
fs = "%" + fs
if fs in fn:
fn = fn.replace(fs, dt.strftime(fs))
try:
import lzma
lh = lzma.open(fn, "wt", encoding="utf-8", errors="replace", preset=0)
except:
import codecs
lh = codecs.open(fn, "w", encoding="utf-8", errors="replace")
argv = [sys.executable] + argv
if hasattr(shlex, "quote"):
argv = [shlex.quote(x) for x in argv]
else:
argv = ['"{}"'.format(x) for x in argv]
lh.write("argv: " + " ".join(argv) + "\n\n" + printed)
return lh
def run(self): def run(self):
thr = threading.Thread(target=self.tcpsrv.run, name="svchub-main") thr = threading.Thread(target=self.tcpsrv.run, name="svchub-main")
thr.daemon = True thr.daemon = True
@ -99,8 +128,15 @@ class SvcHub(object):
print("nailed it", end="") print("nailed it", end="")
finally: finally:
print("\033[0m") print("\033[0m")
if self.logf:
self.logf.close()
def _log_disabled(self, src, msg, c=0): def _log_disabled(self, src, msg, c=0):
if self.logf:
ts = datetime.utcfromtimestamp(time.time())
ts = ts.strftime("%Y-%m%d-%H%M%S.%f")[:-3]
self.logf.write("{} [{}] {}\n".format(ts, src, msg))
pass pass
def _log_enabled(self, src, msg, c=0): def _log_enabled(self, src, msg, c=0):
@ -144,6 +180,9 @@ class SvcHub(object):
except: except:
print(msg.encode("ascii", "replace").decode(), end="") print(msg.encode("ascii", "replace").decode(), end="")
if self.logf:
self.logf.write(msg)
def check_mp_support(self): def check_mp_support(self):
vmin = sys.version_info[1] vmin = sys.version_info[1]
if WINDOWS: if WINDOWS:

View file

@ -66,7 +66,10 @@ class TcpSrv(object):
for srv in self.srv: for srv in self.srv:
srv.listen(self.args.nc) srv.listen(self.args.nc)
ip, port = srv.getsockname() ip, port = srv.getsockname()
self.log("tcpsrv", "listening @ {0}:{1}".format(ip, port)) msg = "listening @ {0}:{1}".format(ip, port)
self.log("tcpsrv", msg)
if self.args.q:
print(msg)
while not self.stopping: while not self.stopping:
if self.args.log_conn: if self.args.log_conn:

View file

@ -9,15 +9,11 @@ import hashlib
import threading import threading
import subprocess as sp import subprocess as sp
from .__init__ import PY2 from .__init__ import PY2, unicode
from .util import fsenc, runcmd, Queue, Cooldown, BytesIO, min_ex from .util import fsenc, runcmd, Queue, Cooldown, BytesIO, min_ex
from .mtag import HAVE_FFMPEG, HAVE_FFPROBE, ffprobe from .mtag import HAVE_FFMPEG, HAVE_FFPROBE, ffprobe
if not PY2:
unicode = str
HAVE_PIL = False HAVE_PIL = False
HAVE_HEIF = False HAVE_HEIF = False
HAVE_AVIF = False HAVE_AVIF = False

View file

@ -342,7 +342,15 @@ class Up2k(object):
for k, v in flags.items() for k, v in flags.items()
] ]
if a: if a:
self.log(" ".join(sorted(a)) + "\033[0m") vpath = "?"
for k, v in self.asrv.vfs.all_vols.items():
if v.realpath == ptop:
vpath = k
if vpath:
vpath += "/"
self.log("/{} {}".format(vpath, " ".join(sorted(a))), "35")
reg = {} reg = {}
path = os.path.join(histpath, "up2k.snap") path = os.path.join(histpath, "up2k.snap")
@ -413,7 +421,7 @@ class Up2k(object):
self.pp.msg = "a{} {}".format(self.pp.n, cdir) self.pp.msg = "a{} {}".format(self.pp.n, cdir)
histpath = self.asrv.vfs.histtab[top] histpath = self.asrv.vfs.histtab[top]
ret = 0 ret = 0
g = statdir(self.log, not self.args.no_scandir, False, cdir) g = statdir(self.log_func, not self.args.no_scandir, False, cdir)
for iname, inf in sorted(g): for iname, inf in sorted(g):
abspath = os.path.join(cdir, iname) abspath = os.path.join(cdir, iname)
lmod = int(inf.st_mtime) lmod = int(inf.st_mtime)

View file

@ -979,8 +979,7 @@ def statdir(logger, scandir, lstat, top):
try: try:
yield [fsdec(fh.name), fh.stat(follow_symlinks=not lstat)] yield [fsdec(fh.name), fh.stat(follow_symlinks=not lstat)]
except Exception as ex: except Exception as ex:
msg = "scan-stat: \033[36m{} @ {}" logger(src, "stat {} @ {}".format(repr(ex), fsdec(fh.path)), 6)
logger(msg.format(repr(ex), fsdec(fh.path)))
else: else:
src = "listdir" src = "listdir"
fun = os.lstat if lstat else os.stat fun = os.lstat if lstat else os.stat
@ -989,11 +988,10 @@ def statdir(logger, scandir, lstat, top):
try: try:
yield [fsdec(name), fun(abspath)] yield [fsdec(name), fun(abspath)]
except Exception as ex: except Exception as ex:
msg = "list-stat: \033[36m{} @ {}" logger(src, "stat {} @ {}".format(repr(ex), fsdec(abspath)), 6)
logger(msg.format(repr(ex), fsdec(abspath)))
except Exception as ex: except Exception as ex:
logger("{}: \033[31m{} @ {}".format(src, repr(ex), top)) logger(src, "{} @ {}".format(repr(ex), top), 1)
def unescape_cookie(orig): def unescape_cookie(orig):