3636import logging .config
3737import logging .handlers # needed for handlers defined there being configurable in logging.conf file
3838import os
39+ import queue
40+ import sys
41+ import time
42+ from typing import Optional
3943import warnings
4044
45+ logging_debugging_path : Optional [str ] = None # if set, write borg.logger debugging log to path/borg-*.log
46+
4147configured = False
48+ borg_serve_log_queue : queue .SimpleQueue = queue .SimpleQueue ()
49+
50+
51+ class BorgQueueHandler (logging .handlers .QueueHandler ):
52+ """borg serve writes log record dicts to a borg_serve_log_queue"""
53+
54+ def prepare (self , record : logging .LogRecord ) -> dict :
55+ return dict (
56+ # kwargs needed for LogRecord constructor:
57+ name = record .name ,
58+ level = record .levelno ,
59+ pathname = record .pathname ,
60+ lineno = record .lineno ,
61+ msg = record .msg ,
62+ args = record .args ,
63+ exc_info = record .exc_info ,
64+ func = record .funcName ,
65+ sinfo = record .stack_info ,
66+ )
67+
68+
69+ class StderrHandler (logging .StreamHandler ):
70+ """
71+ This class is like a StreamHandler using sys.stderr, but always uses
72+ whatever sys.stderr is currently set to rather than the value of
73+ sys.stderr at handler construction time.
74+ """
75+
76+ def __init__ (self , stream = None ):
77+ logging .Handler .__init__ (self )
78+
79+ @property
80+ def stream (self ):
81+ return sys .stderr
82+
83+
84+ class TextProgressFormatter (logging .Formatter ):
85+ def format (self , record : logging .LogRecord ) -> str :
86+ # record.msg contains json (because we always do json for progress log)
87+ j = json .loads (record .msg )
88+ # inside the json, the text log line can be found under "message"
89+ return f"{ j ['message' ]}
90+
91+
92+ class JSONProgressFormatter (logging .Formatter ):
93+ def format (self , record : logging .LogRecord ) -> str :
94+ # record.msg contains json (because we always do json for progress log)
95+ return f"{ record .msg }
96+
4297
4398# use something like this to ignore warnings:
4499# warnings.filterwarnings('ignore', r'... regex for warning message to ignore ...')
@@ -53,14 +108,31 @@ def _log_warning(message, category, filename, lineno, file=None, line=None):
53108 logger .warning (msg )
54109
55110
56- def setup_logging (stream = None , conf_fname = None , env_var = "BORG_LOGGING_CONF" , level = "info" , json = False ):
111+ def remove_handlers (logger ):
112+ for handler in logger .handlers [:]:
113+ handler .flush ()
114+ handler .close ()
115+ logger .removeHandler (handler )
116+
117+
118+ def teardown_logging ():
119+ global configured
120+ logging .shutdown ()
121+ configured = False
122+
123+
124+ def setup_logging (
125+ stream = None , conf_fname = None , env_var = "BORG_LOGGING_CONF" , level = "info" , is_serve = False , log_json = False , func = None
126+ ):
57127 """setup logging module according to the arguments provided
58128
59129 if conf_fname is given (or the config file name can be determined via
60130 the env_var, if given): load this logging configuration.
61131
62132 otherwise, set up a stream handler logger on stderr (by default, if no
63133 stream is provided).
134+
135+ is_serve: are we setting up the logging for "borg serve"?
64136 """
65137 global configured
66138 err_msg = None
@@ -77,25 +149,56 @@ def setup_logging(stream=None, conf_fname=None, env_var="BORG_LOGGING_CONF", lev
77149 logging .config .fileConfig (f )
78150 configured = True
79151 logger = logging .getLogger (__name__ )
80- borg_logger = logging .getLogger ("borg" )
81- borg_logger .json = json
82152 logger .debug (f'using logging configuration read from "{ conf_fname } )
83153 warnings .showwarning = _log_warning
84154 return None
85155 except Exception as err : # XXX be more precise
86156 err_msg = str (err )
157+
87158 # if we did not / not successfully load a logging configuration, fallback to this:
88- logger = logging .getLogger ("" )
89- handler = logging .StreamHandler (stream )
159+ level = level .upper ()
90160 fmt = "%(message)s"
91- formatter = JsonFormatter (fmt ) if json else logging .Formatter (fmt )
161+ formatter = JsonFormatter (fmt ) if log_json else logging .Formatter (fmt )
162+ SHandler = StderrHandler if stream is None else logging .StreamHandler
163+ handler = BorgQueueHandler (borg_serve_log_queue ) if is_serve else SHandler (stream )
92164 handler .setFormatter (formatter )
93- borg_logger = logging .getLogger ("borg" )
94- borg_logger .formatter = formatter
95- borg_logger .json = json
96- logger .addHandler (handler )
97- logger .setLevel (level .upper ())
165+ logger = logging .getLogger ()
166+ remove_handlers (logger )
167+ logger .setLevel (level )
168+
169+ if logging_debugging_path is not None :
170+ # add an addtl. root handler for debugging purposes
171+ log_fname = os .path .join (logging_debugging_path , f"borg-{ 'serve' if is_serve else 'client' } )
172+ handler2 = logging .StreamHandler (open (log_fname , "a" ))
173+ handler2 .setFormatter (formatter )
174+ logger .addHandler (handler2 )
175+ logger .warning (f"--- { func } ) # only handler2 shall get this
176+
177+ logger .addHandler (handler ) # do this late, so handler is not added while debug handler is set up
178+
179+ bop_formatter = JSONProgressFormatter () if log_json else TextProgressFormatter ()
180+ bop_handler = BorgQueueHandler (borg_serve_log_queue ) if is_serve else SHandler (stream )
181+ bop_handler .setFormatter (bop_formatter )
182+ bop_logger = logging .getLogger ("borg.output.progress" )
183+ remove_handlers (bop_logger )
184+ bop_logger .setLevel ("INFO" )
185+ bop_logger .propagate = False
186+
187+ if logging_debugging_path is not None :
188+ # add an addtl. progress handler for debugging purposes
189+ log_fname = os .path .join (logging_debugging_path , f"borg-{ 'serve' if is_serve else 'client' } )
190+ bop_handler2 = logging .StreamHandler (open (log_fname , "a" ))
191+ bop_handler2 .setFormatter (bop_formatter )
192+ bop_logger .addHandler (bop_handler2 )
193+ json_dict = dict (
194+ message = f"--- { func } , operation = 0 , msgid = "" , type = "progress_message" , finished = False , time = time .time ()
195+ )
196+ bop_logger .warning (json .dumps (json_dict )) # only bop_handler2 shall get this
197+
198+ bop_logger .addHandler (bop_handler ) # do this late, so bop_handler is not added while debug handler is set up
199+
98200 configured = True
201+
99202 logger = logging .getLogger (__name__ )
100203 if err_msg :
101204 logger .warning (f'setup_logging for "{ conf_fname } { err_msg } )
0 commit comments