cleaner logging

from https://github.com/lbryio/lbry/pull/94
This commit is contained in:
Jack 2016-07-20 20:56:56 -04:00
parent f40c42dcf0
commit a22dfb3864
5 changed files with 49 additions and 34 deletions

View file

@ -66,6 +66,11 @@ if not os.path.isdir(log_dir):
lbrynet_log = os.path.join(log_dir, LOG_FILE_NAME)
log = logging.getLogger(__name__)
# TODO: configuring a logger on module import drastically reduces the
# amount of control the caller of this code has over logging
#
# Better would be to configure all logging at runtime.
handler = logging.handlers.RotatingFileHandler(lbrynet_log, maxBytes=2097152, backupCount=5)
log.addHandler(handler)
log.setLevel(logging.INFO)
@ -461,7 +466,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
def _announce():
self.announced_startup = True
self.startup_status = STARTUP_STAGES[5]
log.info("[" + str(datetime.now()) + "] Started lbrynet-daemon")
log.info("Started lbrynet-daemon")
if len(self.startup_scripts):
log.info("Scheduling scripts")
reactor.callLater(3, self._run_scripts)
@ -483,7 +488,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
d.addCallback(lambda _: _announce())
return d
log.info("[" + str(datetime.now()) + "] Starting lbrynet-daemon")
log.info("Starting lbrynet-daemon")
self.internet_connection_checker.start(3600)
self.version_checker.start(3600 * 12)
@ -548,14 +553,14 @@ class LBRYDaemon(jsonrpc.JSONRPC):
s = socket.create_connection((host, 80), 2)
self.connected_to_internet = True
except:
log.info("[" + str(datetime.now()) + "] Internet connection not working")
log.info("Internet connection not working")
self.connected_to_internet = False
def _check_lbrynet_connection(self):
def _log_success():
log.info("[" + str(datetime.now()) + "] lbrynet connectivity test passed")
log.info("lbrynet connectivity test passed")
def _log_failure():
log.info("[" + str(datetime.now()) + "] lbrynet connectivity test failed")
log.info("lbrynet connectivity test failed")
wonderfullife_sh = "6f3af0fa3924be98a54766aa2715d22c6c1509c3f7fa32566df4899a41f3530a9f97b2ecb817fa1dcbf1b30553aefaa7"
d = download_sd_blob(self.session, wonderfullife_sh, self.session.base_payment_rate_manager)
@ -573,7 +578,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
self.git_lbryum_version = version
return defer.succeed(None)
except:
log.info("[" + str(datetime.now()) + "] Failed to get lbryum version from git")
log.info("Failed to get lbryum version from git")
self.git_lbryum_version = None
return defer.fail(None)
@ -588,7 +593,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
self.git_lbrynet_version = vr
return defer.succeed(None)
except:
log.info("[" + str(datetime.now()) + "] Failed to get lbrynet version from git")
log.info("Failed to get lbrynet version from git")
self.git_lbrynet_version = None
return defer.fail(None)
@ -1168,15 +1173,15 @@ class LBRYDaemon(jsonrpc.JSONRPC):
return d
d.addCallback(lambda _: finish_deletion(lbry_file))
d.addCallback(lambda _: log.info("[" + str(datetime.now()) + "] Delete lbry file"))
d.addCallback(lambda _: log.info("Delete lbry file"))
return d
def _get_est_cost(self, name):
def _check_est(d, name):
if isinstance(d.result, float):
log.info("[" + str(datetime.now()) + "] Cost est for lbry://" + name + ": " + str(d.result) + "LBC")
log.info("Cost est for lbry://" + name + ": " + str(d.result) + "LBC")
else:
log.info("[" + str(datetime.now()) + "] Timeout estimating cost for lbry://" + name + ", using key fee")
log.info("Timeout estimating cost for lbry://" + name + ", using key fee")
d.cancel()
return defer.succeed(None)
@ -1371,7 +1376,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
Returns: true if daemon completed startup, otherwise false
"""
log.info("[" + str(datetime.now()) + "] is_running: " + str(self.announced_startup))
log.info("is_running: " + str(self.announced_startup))
if self.announced_startup:
return self._render_response(True, OK_CODE)
@ -1409,7 +1414,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
else:
r['message'] = "Catching up with the blockchain"
r['progress'] = 0
log.info("[" + str(datetime.now()) + "] daemon status: " + str(r))
log.info("daemon status: " + str(r))
return self._render_response(r, OK_CODE)
def jsonrpc_is_first_run(self):
@ -1422,7 +1427,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
True if first run, otherwise False
"""
log.info("[" + str(datetime.now()) + "] Check if is first run")
log.info("Check if is first run")
try:
d = self.session.wallet.is_first_run()
except:
@ -1442,7 +1447,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
Startup message, such as first run notification
"""
log.info("[" + str(datetime.now()) + "] Get startup notice")
log.info("Get startup notice")
if self.first_run and not self.session.wallet.wallet_balance:
return self._render_response(self.startup_message, OK_CODE)
@ -1482,7 +1487,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
'lbryum_update_available': lbryum_version < self.git_lbryum_version
}
log.info("[" + str(datetime.now()) + "] Get version info: " + json.dumps(msg))
log.info("Get version info: " + json.dumps(msg))
return self._render_response(msg, OK_CODE)
def jsonrpc_get_settings(self):
@ -1510,7 +1515,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
'start_lbrycrdd': bool,
"""
log.info("[" + str(datetime.now()) + "] Get daemon settings")
log.info("Get daemon settings")
return self._render_response(self.session_settings, OK_CODE)
def jsonrpc_set_settings(self, p):
@ -1531,7 +1536,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
"""
def _log_settings_change():
log.info("[" + str(datetime.now()) + "] Set daemon settings to " + json.dumps(self.session_settings))
log.info("Set daemon settings to " + json.dumps(self.session_settings))
d = self._update_settings(p)
d.addErrback(lambda err: log.info(err.getTraceback()))
@ -1574,7 +1579,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
balance, float
"""
log.info("[" + str(datetime.now()) + "] Get balance")
log.info("Get balance")
return self._render_response(float(self.session.wallet.wallet_balance), OK_CODE)
def jsonrpc_stop(self):
@ -1815,7 +1820,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
return defer.DeferredList(ds)
def _disp(results):
log.info('[' + str(datetime.now()) + '] Found ' + str(len(results)) + ' search results')
log.info('Found ' + str(len(results)) + ' search results')
consolidated_results = []
for r in results:
t = {}
@ -1829,7 +1834,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
return consolidated_results
log.info('[' + str(datetime.now()) + '] Search nametrie: ' + search)
log.info('Search nametrie: ' + search)
d = self.session.wallet.get_nametrie()
d.addCallback(lambda trie: [claim for claim in trie if claim['name'].startswith(search) and 'txid' in claim])
@ -1917,7 +1922,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
return server.failure
def _disp(x):
log.info("[" + str(datetime.now()) + "] Abandoned name claim tx " + str(x))
log.info("Abandoned name claim tx " + str(x))
return self._render_response(x, OK_CODE)
d = defer.Deferred()
@ -2028,7 +2033,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
"""
def _disp(address):
log.info("[" + str(datetime.now()) + "] Got new wallet address: " + address)
log.info("Got new wallet address: " + address)
return defer.succeed(address)
d = self.session.wallet.get_new_address()
@ -2220,7 +2225,7 @@ class LBRYDaemon(jsonrpc.JSONRPC):
exclude_previous = True
if 'message' in p.keys():
log.info("[" + str(datetime.now()) + "] Upload log message: " + str(p['message']))
log.info("Upload log message: " + str(p['message']))
if 'force' in p.keys():
force = p['force']

View file

@ -25,8 +25,13 @@ if not os.path.isdir(log_dir):
os.mkdir(log_dir)
lbrynet_log = os.path.join(log_dir, LOG_FILE_NAME)
DEFAULT_FORMAT = "%(asctime)s %(levelname)-8s %(name)s:%(lineno)d: %(message)s"
DEFAULT_FORMATTER = logging.Formatter(DEFAULT_FORMAT)
log = logging.getLogger(__name__)
handler = logging.handlers.RotatingFileHandler(lbrynet_log, maxBytes=2097152, backupCount=5)
handler.setFormatter(DEFAULT_FORMATTER)
log.addHandler(handler)
log.setLevel(logging.INFO)
@ -57,6 +62,13 @@ def stop():
d.callback(None)
def configureConsoleLogger():
handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(DEFAULT_FORMATTER)
logging.getLogger().addHandler(handler)
logging.getLogger().setLevel(level=logging.INFO)
def start():
parser = argparse.ArgumentParser(description="Launch lbrynet-daemon")
parser.add_argument("--wallet",
@ -75,7 +87,7 @@ def start():
args = parser.parse_args()
if args.logtoconsole:
logging.basicConfig(level=logging.INFO)
configureConsoleLogger()
args = parser.parse_args()
@ -121,4 +133,4 @@ def start():
return
if __name__ == "__main__":
start()
start()

View file

@ -79,7 +79,7 @@ class LBRYFileStreamer(object):
def pauseProducing(self):
self._paused = True
log.info("[" + str(datetime.now()) + "] Pausing producer")
log.info("Pausing producer")
return defer.succeed(None)
def resumeProducing(self):
@ -104,7 +104,7 @@ class LBRYFileStreamer(object):
self._request.write(data)
self._cursor += 1
log.info("[" + str(datetime.now()) + "] Wrote range %s-%s/%s, length: %s, readable: %s, depth: %s" %
log.info("Wrote range %s-%s/%s, length: %s, readable: %s, depth: %s" %
(start_cur, self._cursor, self._file_size, self._cursor - start_cur, readable_bytes, self._depth))
self._sent_bytes = True
@ -117,12 +117,12 @@ class LBRYFileStreamer(object):
self._deferred.addCallback(lambda _: threads.deferToThread(reactor.callLater, self._delay, _check_for_new_data))
return defer.succeed(None)
log.info("[" + str(datetime.now()) + "] Resuming producer")
log.info("Resuming producer")
self._paused = False
self._deferred.addCallback(lambda _: _check_for_new_data())
def stopProducing(self):
log.info("[" + str(datetime.now()) + "] Stopping producer")
log.info("Stopping producer")
self._stopped = True
# self._fileObject.close()
self._deferred.addErrback(lambda err: err.trap(defer.CancelledError))
@ -147,7 +147,7 @@ class HostedLBRYFile(resource.Resource):
#
# range_header = request.getAllHeaders()['range'].replace('bytes=', '').split('-')
# start, stop = int(range_header[0]), range_header[1]
# log.info("[" + str(datetime.now()) + "] GET range %s-%s" % (start, stop))
# log.info("GET range %s-%s" % (start, stop))
# path = os.path.join(self._api.download_directory, stream.file_name)
#
# d = stream.get_total_bytes()

View file

@ -147,6 +147,6 @@ class GetStream(object):
d = _pay_key_fee()
self.downloader = downloader
self.download_path = os.path.join(downloader.download_directory, downloader.file_name)
d.addCallback(lambda _: log.info("[%s] Downloading %s --> %s" % (datetime.now(), self.stream_hash, self.downloader.file_name)))
d.addCallback(lambda _: log.info("Downloading %s --> %s", self.stream_hash, self.downloader.file_name))
d.addCallback(lambda _: self.downloader.start())

View file

@ -48,9 +48,7 @@ class Publisher(object):
def start(self, name, file_path, bid, metadata, fee=None, sources={}):
def _show_result():
message = "[%s] Published %s --> lbry://%s txid: %s" % (datetime.now(), self.file_name, self.publish_name, self.txid)
log.info(message)
log.info("Published %s --> lbry://%s txid: %s", self.file_name, self.publish_name, self.txid)
return defer.succeed(self.txid)
self.publish_name = name