From 02a3eab693c149b5b20d4ffbb9076523387313fa Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 11:39:11 -0500 Subject: [PATCH 1/7] add loggly dependency --- requirements.txt | 1 + 1 file changed, 1 insertion(+) diff --git a/requirements.txt b/requirements.txt index 0f6381005..b27b49f52 100644 --- a/requirements.txt +++ b/requirements.txt @@ -9,6 +9,7 @@ gmpy==1.17 jsonrpc==1.2 jsonrpclib==0.1.7 https://github.com/lbryio/lbryum/tarball/master/#egg=lbryum +loggly-python-handler==1.0.0 miniupnpc==1.9 pbkdf2==1.3 protobuf==3.0.0b3 From 622dc87d84843da297be965257a86d0a2f019b9f Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 14:57:49 -0500 Subject: [PATCH 2/7] Remove log handlers with the same name Also renames functions to follow underscore convention --- lbrynet/core/log_support.py | 34 ++++++++++++++++----- lbrynet/lbrynet_daemon/LBRYDaemonControl.py | 6 ++-- 2 files changed, 28 insertions(+), 12 deletions(-) diff --git a/lbrynet/core/log_support.py b/lbrynet/core/log_support.py index 208157d3d..eb1455c0f 100644 --- a/lbrynet/core/log_support.py +++ b/lbrynet/core/log_support.py @@ -7,18 +7,36 @@ DEFAULT_FORMAT = "%(asctime)s %(levelname)-8s %(name)s:%(lineno)d: %(message)s" DEFAULT_FORMATTER = logging.Formatter(DEFAULT_FORMAT) -def configureConsole(log=None, level=logging.INFO): +def remove_handlers(log, handler_name): + for handler in log.handlers: + if handler.name == handler_name: + log.removeHandler(handler) + + +def _log_decorator(fn): + def helper(*args, **kwargs): + log = kwargs.pop('log', logging.getLogger()) + level = kwargs.pop('level', logging.INFO) + handler = fn(*args, **kwargs) + if handler.name: + remove_handlers(log, handler.name) + log.addHandler(handler) + log.setLevel(level) + return helper + + +@_log_decorator +def configure_console(**kwargs): """Convenience function to configure a logger that outputs to stdout""" - log = log or logging.getLogger() handler = logging.StreamHandler(sys.stdout) handler.setFormatter(DEFAULT_FORMATTER) - log.addHandler(handler) - log.setLevel(level=level) + handler.name = 'console' + return handler -def configureFileHandler(file_name, log=None, level=logging.INFO): - log = log or logging.getLogger() +@_log_decorator +def configure_file_handler(file_name, **kwargs): handler = logging.handlers.RotatingFileHandler(file_name, maxBytes=2097152, backupCount=5) handler.setFormatter(DEFAULT_FORMATTER) - log.addHandler(handler) - log.setLevel(level=level) + handler.name = 'file' + return handler diff --git a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py index 1bfa62eab..9ac321342 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py @@ -74,11 +74,9 @@ def start(): parser.set_defaults(branch=False, launchui=True, logtoconsole=False, quiet=False) args = parser.parse_args() - - log_support.configureFileHandler(lbrynet_log) + log_support.configure_file_handler(lbrynet_log) if args.logtoconsole: - log_support.configureConsole() - + log_support.configure_console() try: JSONRPCProxy.from_url(API_CONNECTION_STRING).is_running() From bc3c2b96ed1c6971c1d03e9c4136faa38fef149a Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 14:59:30 -0500 Subject: [PATCH 3/7] disable noisy loggers --- lbrynet/core/log_support.py | 4 ++++ lbrynet/lbrynet_daemon/LBRYDaemonControl.py | 1 + 2 files changed, 5 insertions(+) diff --git a/lbrynet/core/log_support.py b/lbrynet/core/log_support.py index eb1455c0f..4523b4929 100644 --- a/lbrynet/core/log_support.py +++ b/lbrynet/core/log_support.py @@ -25,6 +25,10 @@ def _log_decorator(fn): return helper +def disable_noisy_loggers(): + logging.getLogger('requests').setLevel(logging.WARNING) + + @_log_decorator def configure_console(**kwargs): """Convenience function to configure a logger that outputs to stdout""" diff --git a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py index 9ac321342..66ec51a33 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py @@ -74,6 +74,7 @@ def start(): parser.set_defaults(branch=False, launchui=True, logtoconsole=False, quiet=False) args = parser.parse_args() + log_support.disable_noisy_loggers() log_support.configure_file_handler(lbrynet_log) if args.logtoconsole: log_support.configure_console() From b8ddbb9a2678a7c7a559553dd5b448d3be77ac3c Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 15:02:36 -0500 Subject: [PATCH 4/7] Add loggly logger It configured twice, once right at startup without the lbry id and then after the settings database is available it gets reconfigured with the lbry id and a session id. --- lbrynet/conf.py | 2 ++ lbrynet/core/log_support.py | 35 +++++++++++++++++++++ lbrynet/lbrynet_daemon/LBRYDaemon.py | 10 ++++++ lbrynet/lbrynet_daemon/LBRYDaemonControl.py | 1 + 4 files changed, 48 insertions(+) diff --git a/lbrynet/conf.py b/lbrynet/conf.py index 466c477ea..eb36b2e69 100644 --- a/lbrynet/conf.py +++ b/lbrynet/conf.py @@ -58,3 +58,5 @@ CURRENCIES = { 'LBC': {'type': 'crypto'}, 'USD': {'type': 'fiat'}, } + +LOGGLY_TOKEN = 'YWRmNGU4NmEtNjkwNC00YjM2LTk3ZjItMGZhODM3ZDhkYzBi' diff --git a/lbrynet/core/log_support.py b/lbrynet/core/log_support.py index 4523b4929..78e9c03f0 100644 --- a/lbrynet/core/log_support.py +++ b/lbrynet/core/log_support.py @@ -1,10 +1,18 @@ +import base64 +import json import logging import logging.handlers import sys +import loggly.handlers + +import lbrynet +from lbrynet import conf + DEFAULT_FORMAT = "%(asctime)s %(levelname)-8s %(name)s:%(lineno)d: %(message)s" DEFAULT_FORMATTER = logging.Formatter(DEFAULT_FORMAT) +LOGGLY_URL = "https://logs-01.loggly.com/inputs/{token}/tag/{tag}" def remove_handlers(log, handler_name): @@ -44,3 +52,30 @@ def configure_file_handler(file_name, **kwargs): handler.setFormatter(DEFAULT_FORMATTER) handler.name = 'file' return handler + + +def get_loggly_url(token=None, version=None): + token = token or base64.b64decode(conf.LOGGLY_TOKEN) + version = version or lbrynet.__version__ + return LOGGLY_URL.format(token=token, tag='lbrynet-' + version) + + +@_log_decorator +def configure_loggly_handler(url=None, **kwargs): + url = url or get_loggly_url() + json_format = { + "loggerName": "%(name)s", + "asciTime": "%(asctime)s", + "fileName": "%(filename)s", + "functionName": "%(funcName)s", + "levelNo": "%(levelno)s", + "lineNo": "%(lineno)d", + "levelName": "%(levelname)s", + "message": "%(message)s", + } + json_format.update(kwargs) + formatter = logging.Formatter(json.dumps(json_format)) + handler = loggly.handlers.HTTPSHandler(url) + handler.setFormatter(formatter) + handler.name = 'loggly' + return handler diff --git a/lbrynet/lbrynet_daemon/LBRYDaemon.py b/lbrynet/lbrynet_daemon/LBRYDaemon.py index 08bd27d3a..093c0704b 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemon.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemon.py @@ -42,6 +42,7 @@ from lbrynet.lbrynet_daemon.LBRYDownloader import GetStream from lbrynet.lbrynet_daemon.LBRYPublisher import Publisher from lbrynet.lbrynet_daemon.LBRYExchangeRateManager import ExchangeRateManager from lbrynet.lbrynet_daemon.Lighthouse import LighthouseClient +from lbrynet.core import log_support from lbrynet.core import utils from lbrynet.core.LBRYMetadata import verify_name_characters from lbrynet.core.utils import generate_id @@ -932,6 +933,7 @@ class LBRYDaemon(jsonrpc.JSONRPC): d = self.settings.start() d.addCallback(lambda _: self.settings.get_lbryid()) d.addCallback(self._set_lbryid) + d.addCallback(lambda _: self._modify_loggly_formatter()) return d def _set_lbryid(self, lbryid): @@ -947,6 +949,14 @@ class LBRYDaemon(jsonrpc.JSONRPC): d = self.settings.save_lbryid(self.lbryid) return d + def _modify_loggly_formatter(self): + session_id = base58.b58encode(generate_id()) + log_support.configure_loggly_handler( + lbry_id=base58.b58encode(self.lbryid), + session_id=session_id + ) + + def _setup_lbry_file_manager(self): self.startup_status = STARTUP_STAGES[3] self.lbry_file_metadata_manager = DBLBRYFileMetadataManager(self.db_dir) diff --git a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py index 66ec51a33..507b3c168 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemonControl.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemonControl.py @@ -76,6 +76,7 @@ def start(): log_support.disable_noisy_loggers() log_support.configure_file_handler(lbrynet_log) + log_support.configure_loggly_handler() if args.logtoconsole: log_support.configure_console() From 9a9b540701511441cf2cf538cf33d3601af956cb Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 15:04:50 -0500 Subject: [PATCH 5/7] Move some ServerRequestHandling logging to debug level --- lbrynet/core/server/ServerRequestHandler.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lbrynet/core/server/ServerRequestHandler.py b/lbrynet/core/server/ServerRequestHandler.py index 99048c205..e1685c37b 100644 --- a/lbrynet/core/server/ServerRequestHandler.py +++ b/lbrynet/core/server/ServerRequestHandler.py @@ -99,8 +99,8 @@ class ServerRequestHandler(object): d.addCallback(lambda _: self.blob_sender.send_blob_if_requested(self)) d.addCallbacks(lambda _: self.finished_response(), self.request_failure_handler) else: - log.info("Request buff not a valid json message") - log.info("Request buff: %s", str(self.request_buff)) + log.debug("Request buff not a valid json message") + log.debug("Request buff: %s", str(self.request_buff)) else: log.warning("The client sent data when we were uploading a file. This should not happen") From 0ba04265911f997fedb7f9ba04f15d0cfd511061 Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 15:06:48 -0500 Subject: [PATCH 6/7] Refactor lbrycrdd path function for osx --- lbrynet/lbrynet_daemon/LBRYDaemon.py | 27 +++++++++++++++++++-------- 1 file changed, 19 insertions(+), 8 deletions(-) diff --git a/lbrynet/lbrynet_daemon/LBRYDaemon.py b/lbrynet/lbrynet_daemon/LBRYDaemon.py index 093c0704b..c3df1b00b 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemon.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemon.py @@ -320,14 +320,7 @@ class LBRYDaemon(jsonrpc.JSONRPC): else: self.wallet_dir = os.path.join(get_path(FOLDERID.RoamingAppData, UserHandle.current), "lbryum") elif sys.platform == "darwin": - # use the path from the bundle if its available. - try: - import Foundation - bundle = Foundation.NSBundle.mainBundle() - self.lbrycrdd_path = bundle.pathForResource_ofType_('lbrycrdd', None) - except Exception: - log.exception('Failed to get path from bundle, falling back to default') - self.lbrycrdd_path = "./lbrycrdd" + self.lbrycrdd_path = get_darwin_lbrycrdd_path() if self.wallet_type == "lbrycrd": self.wallet_dir = user_data_dir("lbrycrd") else: @@ -2384,6 +2377,24 @@ def get_output_callback(params): return callback +def get_darwin_lbrycrdd_path(): + # use the path from the bundle if its available. + default = "./lbrycrdd" + try: + import Foundation + except ImportError: + log.warning('Foundation module not installed, falling back to default lbrycrdd path') + return default + else: + try: + bundle = Foundation.NSBundle.mainBundle() + return bundle.pathForResource_ofType_('lbrycrdd', None) + except Exception: + log.exception('Failed to get path from bundle, falling back to default') + return default + + + class _DownloadNameHelper(object): def __init__(self, daemon, name, timeout=DEFAULT_TIMEOUT, download_directory=None, file_name=None, wait_for_write=True): From 9033eac5b1613ab6cfdd210c85bc28764e864182 Mon Sep 17 00:00:00 2001 From: Job Evers-Meltzer Date: Mon, 8 Aug 2016 15:07:25 -0500 Subject: [PATCH 7/7] Remove commented code --- lbrynet/lbrynet_daemon/LBRYDaemon.py | 63 ---------------------------- 1 file changed, 63 deletions(-) diff --git a/lbrynet/lbrynet_daemon/LBRYDaemon.py b/lbrynet/lbrynet_daemon/LBRYDaemon.py index c3df1b00b..c91846c1b 100644 --- a/lbrynet/lbrynet_daemon/LBRYDaemon.py +++ b/lbrynet/lbrynet_daemon/LBRYDaemon.py @@ -478,8 +478,6 @@ class LBRYDaemon(jsonrpc.JSONRPC): log.info("Scheduling scripts") reactor.callLater(3, self._run_scripts) - # self.lbrynet_connection_checker.start(3600) - if self.first_run: d = self._upload_log(log_type="first_run") elif self.upload_log: @@ -487,11 +485,6 @@ class LBRYDaemon(jsonrpc.JSONRPC): else: d = defer.succeed(None) - # if float(self.session.wallet.wallet_balance) == 0.0: - # d.addCallback(lambda _: self._check_first_run()) - # d.addCallback(self._show_first_run_result) - - # d.addCallback(lambda _: _wait_for_credits() if self.requested_first_run_credits else _announce()) d.addCallback(lambda _: _announce()) return d @@ -1016,62 +1009,6 @@ class LBRYDaemon(jsonrpc.JSONRPC): return dl - # def _check_first_run(self): - # def _set_first_run_false(): - # log.info("Not first run") - # self.first_run = False - # self.session_settings['requested_first_run_credits'] = True - # f = open(self.daemon_conf, "w") - # f.write(json.dumps(self.session_settings)) - # f.close() - # return 0.0 - # - # if self.wallet_type == 'lbryum': - # d = self.session.wallet.is_first_run() - # d.addCallback(lambda is_first_run: self._do_first_run() if is_first_run or not self.requested_first_run_credits - # else _set_first_run_false()) - # else: - # d = defer.succeed(None) - # d.addCallback(lambda _: _set_first_run_false()) - # return d - # - # def _do_first_run(self): - # def send_request(url, data): - # log.info("Requesting first run credits") - # r = requests.post(url, json=data) - # if r.status_code == 200: - # self.requested_first_run_credits = True - # self.session_settings['requested_first_run_credits'] = True - # f = open(self.daemon_conf, "w") - # f.write(json.dumps(self.session_settings)) - # f.close() - # return r.json()['credits_sent'] - # return 0.0 - # - # def log_error(err): - # log.warning("unable to request free credits. %s", err.getErrorMessage()) - # return 0.0 - # - # def request_credits(address): - # url = "http://credreq.lbry.io/requestcredits" - # data = {"address": address} - # d = threads.deferToThread(send_request, url, data) - # d.addErrback(log_error) - # return d - # - # self.first_run = True - # d = self.session.wallet.get_new_address() - # d.addCallback(request_credits) - # - # return d - # - # def _show_first_run_result(self, credits_received): - # if credits_received != 0.0: - # points_string = locale.format_string("%.2f LBC", (round(credits_received, 2),), grouping=True) - # self.startup_message = "Thank you for testing the alpha version of LBRY! You have been given %s for free because we love you. Please hang on for a few minutes for the next block to be mined. When you refresh this page and see your credits you're ready to go!." % points_string - # else: - # self.startup_message = None - def _setup_stream_identifier(self): file_saver_factory = LBRYFileSaverFactory(self.session.peer_finder, self.session.rate_limiter, self.session.blob_manager, self.stream_info_manager,