Merge pull request #204 from lbryio/cleanup-logging

Cleanup logging
This commit is contained in:
Job Evers‐Meltzer 2016-10-28 15:56:54 -05:00 committed by GitHub
commit 46cfa20f65
11 changed files with 240 additions and 177 deletions

View file

@ -3,10 +3,12 @@ import os
import sys
from appdirs import user_data_dir
LINUX = 1
DARWIN = 2
WINDOWS = 3
if sys.platform.startswith("darwin"):
platform = DARWIN
default_download_directory = os.path.join(os.path.expanduser("~"), 'Downloads')
@ -228,6 +230,23 @@ class Config(DefaultSettings):
return "http://%s:%i" % (DEFAULT_SETTINGS.API_INTERFACE, self.api_port)
def get_data_dir():
if sys.platform != "darwin":
data_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
data_dir = user_data_dir("LBRY")
if not os.path.isdir(data_dir):
os.mkdir(data_dir)
def get_log_filename():
"""Return the log file for this platform.
Also ensure the containing directory exists
"""
return os.path.join(get_data_dir(), settings.LOG_FILE_NAME)
# TODO: don't load the configuration automatically. The configuration
# should be loaded at runtime, not at module import time. Module
# import should have no side-effects. This is also bad because

View file

@ -1,15 +1,20 @@
import datetime
import json
import logging
import logging.handlers
import os
import platform
import sys
import traceback
import requests
from requests_futures.sessions import FuturesSession
import lbrynet
from lbrynet.conf import settings
from lbrynet.core import utils
session = FuturesSession()
@ -54,6 +59,12 @@ def remove_handlers(log, handler_name):
def _log_decorator(fn):
"""Configure a logging handler.
`fn` is a function that returns a logging handler. The returned
handler has its log-level set and is attached to the specified
logger or the root logger.
"""
def helper(*args, **kwargs):
log = kwargs.pop('log', logging.getLogger())
level = kwargs.pop('level', logging.INFO)
@ -66,8 +77,12 @@ def _log_decorator(fn):
remove_handlers(log, handler.name)
handler.setLevel(level)
log.addHandler(handler)
# need to reduce the logger's level down to the
# handler's level or else the handler won't
# get those messages
if log.level > level:
log.setLevel(level)
return handler
return helper
@ -76,19 +91,10 @@ def disable_third_party_loggers():
logging.getLogger('urllib3').setLevel(logging.WARNING)
logging.getLogger('BitcoinRPC').setLevel(logging.INFO)
def disable_noisy_loggers():
logging.getLogger('lbrynet.analytics.api').setLevel(logging.INFO)
logging.getLogger('lbrynet.core').setLevel(logging.INFO)
logging.getLogger('lbrynet.dht').setLevel(logging.INFO)
logging.getLogger('lbrynet.lbrynet_daemon').setLevel(logging.INFO)
logging.getLogger('lbrynet.core.Wallet').setLevel(logging.INFO)
logging.getLogger('lbrynet.lbryfile').setLevel(logging.INFO)
logging.getLogger('lbrynet.lbryfilemanager').setLevel(logging.INFO)
@_log_decorator
def configure_console(**kwargs):
"""Convenience function to configure a logger that outputs to stdout"""
"""Convenience function to configure a log-handler that outputs to stdout"""
handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(DEFAULT_FORMATTER)
handler.name = 'console'
@ -97,6 +103,7 @@ def configure_console(**kwargs):
@_log_decorator
def configure_file_handler(file_name, **kwargs):
"""Convenience function to configure a log-handler that writes to `file_name`"""
handler = logging.handlers.RotatingFileHandler(file_name, maxBytes=2097152, backupCount=5)
handler.setFormatter(DEFAULT_FORMATTER)
handler.name = 'file'
@ -153,3 +160,120 @@ def failure(failure, log, msg, *args):
"""
args += (failure.getErrorMessage(),)
log.error(msg, *args, exc_info=failure.getTracebackObject())
def convert_verbose(verbose):
"""Convert the results of the --verbose flag into a list of logger names
if --verbose is not provided, args.verbose will be None and logging
should be at the info level.
if --verbose is provided, but not followed by any arguments, then
args.verbose = [] and debug logging should be enabled for all of lbrynet
if --verbose is provided and followed by arguments, those arguments
will be in a list
"""
if verbose is None:
return []
if verbose == []:
return ['lbrynet']
return verbose
def configure_logging(file_name, console, verbose=None):
"""Apply the default logging configuration.
Enables two log-handlers at the INFO level: a file logger and a loggly logger.
Optionally turns on a console logger that defaults to the INFO level, with
specified loggers being set to the DEBUG level.
Args:
file_name: the file to which logs should be saved
console: If true, enable a console logger
verbose: a list of loggers to set to debug level.
See `convert_verbose` for more details.
"""
verbose = convert_verbose(verbose)
configure_file_handler(file_name)
configure_loggly_handler()
disable_third_party_loggers()
if console:
# if there are some loggers at the debug level, we need
# to enable the console to allow debug. Otherwise, only
# allow info.
level = 'DEBUG' if verbose else 'INFO'
handler = configure_console(level=level)
if verbose:
handler.addFilter(LoggerNameFilter(verbose))
class LoggerNameFilter(object):
"""Filter a log record based on its name.
Allows all info level and higher records to pass thru.
Debug records pass if the log record name (or a parent) match
the input list of logger names.
"""
def __init__(self, logger_names):
self.logger_names = logger_names
def filter(self, record):
if record.levelno >= logging.INFO:
return True
name = record.name
while name:
if name in self.logger_names:
return True
name = get_parent(name)
return False
def get_parent(logger_name):
names = logger_name.split('.')
if len(names) == 1:
return ''
names = names[:-1]
return '.'.join(names)
class LogUploader(object):
def __init__(self, log_name, log_file, log_size):
self.log_name = log_name
self.log_file = log_file
self.log_size = log_size
def upload(self, exclude_previous, id_hash, log_type):
if not os.path.isfile(self.log_file):
return
log_contents = self.log_contents(exclude_previous)
params = {
'date': datetime.datetime.utcnow().strftime('%Y%m%d-%H%M%S'),
'hash': id_hash,
'sys': platform.system(),
'type': self.get_type(log_type),
'log': log_contents
}
requests.post(settings.LOG_POST_URL, params)
def log_contents(self, exclude_previous):
with open(self.log_file) as f:
if exclude_previous:
f.seek(self.log_size)
log_contents = f.read()
else:
log_contents = f.read()
return log_contents
def get_type(self, log_type):
if log_type:
return "%s-%s" % (self.log_name, log_type)
else:
return self.log_name
@classmethod
def load(cls, log_name, log_file):
if os.path.isfile(log_file):
with open(log_file, 'r') as f:
log_size = len(f.read())
else:
log_size = 0
return cls(log_name, log_file, log_size)

View file

@ -6,6 +6,7 @@ import json
import random
import os
import socket
import sys
import yaml
from lbrynet.conf import settings
@ -119,3 +120,9 @@ def check_connection(server="www.lbry.io", port=80):
"Failed to connect to %s:%s. Maybe the internet connection is not working",
server, port, exc_info=True)
return False
def setup_certs_for_windows():
if getattr(sys, 'frozen', False) and os.name == "nt":
cert_path = os.path.join(os.path.dirname(sys.executable), "cacert.pem")
os.environ["REQUESTS_CA_BUNDLE"] = cert_path

View file

@ -28,6 +28,7 @@ from lbryum.version import LBRYUM_VERSION as lbryum_version
from lbrynet import __version__ as lbrynet_version
from lbrynet.conf import settings as lbrynet_settings
from lbrynet import analytics
from lbrynet import conf
from lbrynet import reflector
from lbrynet.metadata.Metadata import Metadata, verify_name_characters
from lbrynet.metadata.Fee import FeeValidator
@ -56,26 +57,23 @@ from lbrynet.lbrynet_daemon.ExchangeRateManager import ExchangeRateManager
from lbrynet.lbrynet_daemon.Lighthouse import LighthouseClient
from lbrynet.lbrynet_daemon.auth.server import AuthJSONRPCServer
from lbrynet.metadata.Metadata import Metadata, verify_name_characters
from lbrynet.core import log_support
from lbrynet.core import utils
from lbrynet.core.utils import generate_id
from lbrynet.lbrynet_console.Settings import Settings
from lbrynet.core.StreamDescriptor import StreamDescriptorIdentifier, download_sd_blob, BlobStreamDescriptorReader
from lbrynet.core.Session import Session
from lbrynet.core.PTCWallet import PTCWallet
from lbrynet.core.Wallet import LBRYcrdWallet, LBRYumWallet
from lbrynet.lbryfilemanager.EncryptedFileManager import EncryptedFileManager
from lbrynet.lbryfile.EncryptedFileMetadataManager import DBEncryptedFileMetadataManager, TempEncryptedFileMetadataManager
from lbrynet import reflector
# TODO: this code snippet is everywhere. Make it go away
if sys.platform != "darwin":
log_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
log_dir = user_data_dir("LBRY")
if not os.path.isdir(log_dir):
os.mkdir(log_dir)
lbrynet_log = os.path.join(log_dir, lbrynet_settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)
if os.path.isfile(lbrynet_log):
with open(lbrynet_log, 'r') as f:
PREVIOUS_NET_LOG = len(f.read())
else:
PREVIOUS_NET_LOG = 0
INITIALIZING_CODE = 'initializing'
LOADING_DB_CODE = 'loading_db'
@ -275,12 +273,16 @@ class Daemon(AuthJSONRPCServer):
self.ui_version = None
self.ip = None
self.first_run = None
self.log_file = lbrynet_log
self.log_file = conf.get_log_file()
self.current_db_revision = 1
self.session = None
self.first_run_after_update = False
self.uploaded_temp_files = []
self._session_id = base58.b58encode(generate_id())
# TODO: this should probably be passed into the daemon, or
# possibly have the entire log upload functionality taken out
# of the daemon, but I don't want to deal with that now
self.log_uploader = log_support.LogUploader.load('lbrynet', conf.get_log_file())
self.analytics_manager = None
self.lbryid = PENDING_LBRY_ID
@ -324,7 +326,6 @@ class Daemon(AuthJSONRPCServer):
self.lbry_file_metadata_manager = None
self.lbry_file_manager = None
@AuthJSONRPCServer.subhandler
def _exclude_lbrycrd_only_commands_from_lbryum_session(self, request):
request.content.seek(0, 0)
@ -400,7 +401,6 @@ class Daemon(AuthJSONRPCServer):
self.exchange_rate_manager.start()
d = defer.Deferred()
if lbrynet_settings.host_ui:
self.lbry_ui_manager.update_checker.start(1800, now=False)
d.addCallback(lambda _: self.lbry_ui_manager.setup())
@ -621,37 +621,20 @@ class Daemon(AuthJSONRPCServer):
ds = []
for handler in query_handlers:
ds.append(self.settings.get_query_handler_status(handler.get_primary_query_identifier()))
query_id = handler.get_primary_query_identifier()
ds.append(self.settings.get_query_handler_status(query_id))
dl = defer.DeferredList(ds)
dl.addCallback(_set_query_handlers)
return dl
def _upload_log(self, log_type=None, exclude_previous=False, force=False):
if self.upload_log or force:
for lm, lp in [('lbrynet', lbrynet_log)]:
if os.path.isfile(lp):
if exclude_previous:
with open( lp, "r") as f:
f.seek(PREVIOUS_NET_LOG)
log_contents = f.read()
else:
with open(lp, "r") as f:
log_contents = f.read()
if self.lbryid is not PENDING_LBRY_ID:
id_hash = base58.b58encode(self.lbryid)[:20]
else:
id_hash = self.lbryid
params = {
'date': datetime.utcnow().strftime('%Y%m%d-%H%M%S'),
'hash': id_hash,
'sys': platform.system(),
'type': "%s-%s" % (lm, log_type) if log_type else lm,
'log': log_contents
}
requests.post(lbrynet_settings.LOG_POST_URL, params)
return defer.succeed(None)
else:
return defer.succeed(None)
if self.lbryid is not PENDING_LBRY_ID:
id_hash = base58.b58encode(self.lbryid)[:20]
else:
id_hash = self.lbryid
self.log_uploader.upload(exclude_previous, self.lbryid, log_type)
return defer.succeed(None)
def _clean_up_temp_files(self):
for path in self.uploaded_temp_files:
@ -2187,7 +2170,8 @@ class Daemon(AuthJSONRPCServer):
check_require = True
if 'path' in p:
d = self.lbry_ui_manager.setup(user_specified=p['path'], check_requirements=check_require)
d = self.lbry_ui_manager.setup(
user_specified=p['path'], check_requirements=check_require)
elif 'branch' in p:
d = self.lbry_ui_manager.setup(branch=p['branch'], check_requirements=check_require)
else:

View file

@ -2,7 +2,6 @@ import argparse
import logging.handlers
import os
import webbrowser
import sys
from twisted.web import server, guard
from twisted.internet import defer, reactor, error
@ -11,25 +10,17 @@ from jsonrpc.proxy import JSONRPCProxy
from lbrynet.lbrynet_daemon.auth.auth import PasswordChecker, HttpPasswordRealm
from lbrynet.lbrynet_daemon.auth.util import initialize_api_key_file
from lbrynet import conf
from lbrynet.core import log_support
from lbrynet.core import utils
from lbrynet.lbrynet_daemon.DaemonServer import DaemonServer
from lbrynet.lbrynet_daemon.DaemonRequest import DaemonRequest
from lbrynet.conf import settings
log_dir = settings.data_dir
if not os.path.isdir(log_dir):
os.mkdir(log_dir)
lbrynet_log = os.path.join(log_dir, settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)
if getattr(sys, 'frozen', False) and os.name == "nt":
os.environ["REQUESTS_CA_BUNDLE"] = os.path.join(os.path.dirname(sys.executable), "cacert.pem")
def test_internet_connection():
return utils.check_connection()
@ -55,45 +46,30 @@ def start():
help="lbrycrd or lbryum, default lbryum",
type=str,
default='lbryum')
parser.add_argument("--ui",
help="path to custom UI folder",
default=None)
parser.add_argument("--branch",
help="Branch of lbry-web-ui repo to use, defaults on master",
default=settings.ui_branch)
parser.add_argument("--http-auth",
dest="useauth",
action="store_true")
parser.add_argument('--no-launch',
dest='launchui',
action="store_false")
parser.add_argument('--log-to-console',
dest='logtoconsole',
action="store_true")
parser.add_argument('--quiet',
dest='quiet',
action="store_true")
parser.add_argument('--verbose',
action='store_true',
help='enable more debug output for the console')
parser.set_defaults(branch=False, launchui=True, logtoconsole=False, quiet=False, useauth=settings.use_auth_http)
parser.add_argument("--ui", help="path to custom UI folder", default=None)
parser.add_argument(
"--branch",
help='Branch of lbry-web-ui repo to use, defaults to {}'.format(settings.ui_branch),
default=settings.ui_branch)
parser.add_argument('--no-launch', dest='launchui', action="store_false")
parser.add_argument("--http-auth", dest="useauth", action="store_true")
parser.add_argument(
'--log-to-console', dest='logtoconsole', action='store_true',
help=('Set to enable console logging. Set the --verbose flag '
' to enable more detailed console logging'))
parser.add_argument(
'--quiet', dest='quiet', action="store_true",
help=('If log-to-console is not set, setting this disables all console output. '
'If log-to-console is set, this argument is ignored'))
parser.add_argument(
'--verbose', nargs="*",
help=('Enable debug output. Optionally specify loggers for which debug output '
'should selectively be applied.'))
args = parser.parse_args()
log_support.configure_file_handler(lbrynet_log)
log_support.configure_loggly_handler()
if args.logtoconsole:
log_support.configure_console(level='DEBUG')
log_support.disable_third_party_loggers()
if not args.verbose:
log_support.disable_noisy_loggers()
utils.setup_certs_for_windows()
lbrynet_log = conf.get_log_file()
log_support.configure_logging(lbrynet_log, args.logtoconsole, args.verbose)
to_pass = {}
settings_path = os.path.join(settings.data_dir, "daemon_settings.yml")

View file

@ -1,29 +1,21 @@
import logging
import os
import sys
from appdirs import user_data_dir
from twisted.internet import defer
from lbrynet import conf
from lbrynet.lbrynet_daemon.Daemon import Daemon
from lbrynet.lbrynet_daemon.Resources import LBRYindex, HostedEncryptedFile, EncryptedFileUpload
from lbrynet.conf import settings
# TODO: omg, this code is essentially duplicated in Daemon
if sys.platform != "darwin":
data_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
data_dir = user_data_dir("LBRY")
if not os.path.isdir(data_dir):
os.mkdir(data_dir)
lbrynet_log = os.path.join(data_dir, settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)
class DaemonServer(object):
def _setup_server(self):
self.root = LBRYindex(os.path.join(os.path.join(data_dir, "lbry-ui"), "active"))
ui_path = os.path.join(conf.get_data_dir(), "lbry-ui", "active")
self.root = LBRYindex(ui_path)
self._api = Daemon(self.root)
self.root.putChild("view", HostedEncryptedFile(self._api))
self.root.putChild("upload", EncryptedFileUpload(self._api))

View file

@ -1,10 +1,8 @@
import json
import logging
import os
import sys
from copy import deepcopy
from appdirs import user_data_dir
from twisted.internet import defer
from twisted.internet.task import LoopingCall
@ -20,28 +18,24 @@ DOWNLOAD_TIMEOUT_CODE = 'timeout'
DOWNLOAD_RUNNING_CODE = 'running'
DOWNLOAD_STOPPED_CODE = 'stopped'
STREAM_STAGES = [
(INITIALIZING_CODE, 'Initializing...'),
(DOWNLOAD_METADATA_CODE, 'Downloading metadata'),
(DOWNLOAD_RUNNING_CODE, 'Started stream'),
(DOWNLOAD_STOPPED_CODE, 'Paused stream'),
(DOWNLOAD_TIMEOUT_CODE, 'Stream timed out')
]
(INITIALIZING_CODE, 'Initializing...'),
(DOWNLOAD_METADATA_CODE, 'Downloading metadata'),
(DOWNLOAD_RUNNING_CODE, 'Started stream'),
(DOWNLOAD_STOPPED_CODE, 'Paused stream'),
(DOWNLOAD_TIMEOUT_CODE, 'Stream timed out')
]
if sys.platform != "darwin":
log_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
log_dir = user_data_dir("LBRY")
if not os.path.isdir(log_dir):
os.mkdir(log_dir)
lbrynet_log = os.path.join(log_dir, settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)
class GetStream(object):
def __init__(self, sd_identifier, session, wallet, lbry_file_manager, exchange_rate_manager,
max_key_fee, data_rate=0.5, timeout=settings.download_timeout, download_directory=None, file_name=None):
def __init__(self, sd_identifier, session, wallet,
lbry_file_manager, exchange_rate_manager,
max_key_fee, data_rate=0.5, timeout=None,
download_directory=None, file_name=None):
if timeout is None:
timeout = settings.download_timeout
self.wallet = wallet
self.resolved_name = None
self.description = None

View file

@ -1,10 +1,9 @@
import logging
import mimetypes
import os
import sys
import random
from appdirs import user_data_dir
from twisted.internet import threads, defer, reactor
from lbrynet.core.Error import InsufficientFundsError
from lbrynet.lbryfilemanager.EncryptedFileCreator import create_lbry_file
@ -13,17 +12,8 @@ from lbrynet.metadata.Metadata import Metadata
from lbrynet.lbryfilemanager.EncryptedFileDownloader import ManagedEncryptedFileDownloader
from lbrynet import reflector
from lbrynet.conf import settings
from twisted.internet import threads, defer, reactor
if sys.platform != "darwin":
log_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
log_dir = user_data_dir("LBRY")
if not os.path.isdir(log_dir):
os.mkdir(log_dir)
lbrynet_log = os.path.join(log_dir, settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)

View file

@ -15,15 +15,7 @@ from lbryum.version import LBRYUM_VERSION as lbryum_version
from zipfile import ZipFile
from appdirs import user_data_dir
if sys.platform != "darwin":
log_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
log_dir = user_data_dir("LBRY")
if not os.path.isdir(log_dir):
os.mkdir(log_dir)
lbrynet_log = os.path.join(log_dir, settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)

View file

@ -4,32 +4,22 @@ install(runner=AppHelper.runEventLoop)
from twisted.internet import reactor
import logging
import sys
import os
from appdirs import user_data_dir
from lbrynet import conf
from lbrynet.core import log_support
from LBRYApp import LBRYDaemonApp
if sys.platform != "darwin":
log_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
else:
log_dir = user_data_dir("LBRY")
if not os.path.isdir(log_dir):
os.mkdir(log_dir)
LOG_FILENAME = os.path.join(log_dir, 'lbrynet-daemon.log')
log = logging.getLogger(__name__)
handler = logging.handlers.RotatingFileHandler(LOG_FILENAME, maxBytes=2097152, backupCount=5)
log.addHandler(handler)
logging.basicConfig(level=logging.INFO)
log = logging.getLogger()
def main():
log_file = conf.get_log_filename()
log_support.configure_logging(log_file, console=False)
app = LBRYDaemonApp.sharedApplication()
reactor.addSystemEventTrigger("after", "shutdown", AppHelper.stopEventLoop)
reactor.run()
if __name__ == "__main__":
main()

View file

@ -1,6 +1,5 @@
import logging
import os
import socket
import sys
import threading
import webbrowser
@ -11,13 +10,14 @@ import win32gui_struct
from jsonrpc.proxy import JSONRPCProxy
from twisted.internet import reactor, error
from twisted.web import server
import twisted
try:
import winxpgui as win32gui
except ImportError:
import win32gui
from lbrynet import conf
from lbrynet.core import log_support
from lbrynet.core import utils
from lbrynet.lbrynet_daemon import DaemonControl
from lbrynet.lbrynet_daemon.DaemonServer import DaemonServer
@ -26,17 +26,8 @@ from lbrynet.conf import settings
from packaging.uri_handler.LBRYURIHandler import LBRYURIHandler
# TODO: omg, this code is essentially duplicated in LBRYDaemon
data_dir = os.path.join(os.path.expanduser("~"), ".lbrynet")
if not os.path.isdir(data_dir):
os.mkdir(data_dir)
lbrynet_log = os.path.join(data_dir, settings.LOG_FILE_NAME)
log = logging.getLogger(__name__)
if getattr(sys, 'frozen', False) and os.name == "nt":
os.environ["REQUESTS_CA_BUNDLE"] = os.path.join(os.path.dirname(sys.executable), "cacert.pem")
def test_internet_connection():
return utils.check_connection()
@ -282,7 +273,11 @@ def main(lbry_name=None):
DaemonControl.start_server_and_listen(launchui=True, use_auth=False)
reactor.run()
if __name__ == '__main__':
utils.setup_certs_for_windows()
log_file = conf.get_log_filename()
log_support.configure_logging(log_file, console=False)
lbry_daemon = JSONRPCProxy.from_url(settings.API_CONNECTION_STRING)
try: