diff --git a/bench/app.py b/bench/app.py index 28b1d1e8..c3950cf1 100755 --- a/bench/app.py +++ b/bench/app.py @@ -23,8 +23,7 @@ from bench.config.common_site_config import get_config from bench.utils import color, CommandFailedError, build_assets, check_git_for_shallow_clone, exec_cmd, get_cmd_output, get_frappe, restart_supervisor_processes, restart_systemd_processes, run_frappe_cmd -logging.basicConfig(level="INFO") -logger = logging.getLogger(__name__) +logger = logging.getLogger(bench.PROJECT_NAME) class InvalidBranchException(Exception): pass @@ -140,7 +139,7 @@ Do you want to continue and overwrite it?'''.format(repo_name)): install_app(app=app_name, bench_path=bench_path, verbose=verbose, skip_assets=skip_assets) sys.exit() - logger.info('Getting app {0}'.format(repo_name)) + logger.log('Getting app {0}'.format(repo_name)) exec_cmd("git clone {git_url} {branch} {shallow_clone} --origin upstream".format( git_url=git_url, shallow_clone=shallow_clone, @@ -165,7 +164,7 @@ def get_app_name(bench_path, repo_name): def new_app(app, bench_path='.'): # For backwards compatibility app = app.lower().replace(" ", "_").replace("-", "_") - logger.info('creating new app {}'.format(app)) + logger.log('creating new app {}'.format(app)) apps = os.path.abspath(os.path.join(bench_path, 'apps')) bench.set_frappe_version(bench_path=bench_path) @@ -179,6 +178,7 @@ def new_app(app, bench_path='.'): def install_app(app, bench_path=".", verbose=False, no_cache=False, postprocess=True, skip_assets=False): print('\n{0}Installing {1}{2}'.format(color.yellow, app, color.nc)) + logger.log("installing {}".format(app)) pip_path = os.path.join(bench_path, "env", "bin", "pip") quiet_flag = "-q" if not verbose else "" @@ -272,7 +272,7 @@ Here are your choices: add_to_excluded_apps_txt(app, bench_path=bench_path) print("Skipping pull for app {}, since remote doesn't exist, and adding it to excluded apps".format(app)) continue - logger.info('pulling {0}'.format(app)) + logger.log('pulling {0}'.format(app)) if reset: exec_cmd("git fetch --all", cwd=app_dir) exec_cmd("git reset --hard {remote}/{branch}".format( diff --git a/bench/cli.py b/bench/cli.py index 09c001d8..0cc53310 100755 --- a/bench/cli.py +++ b/bench/cli.py @@ -14,9 +14,8 @@ import bench from bench.app import get_apps from bench.commands import bench_command from bench.config.common_site_config import get_config -from bench.utils import PatchError, bench_cache_file, check_latest_version, drop_privileges, find_parent_bench, generate_command_cache, get_cmd_output, get_env_cmd, get_frappe, is_bench_directory, is_dist_editable, is_root, log +from bench.utils import PatchError, bench_cache_file, check_latest_version, drop_privileges, find_parent_bench, generate_command_cache, get_cmd_output, get_env_cmd, get_frappe, is_bench_directory, is_dist_editable, is_root, log, setup_logging -logger = logging.getLogger(bench.PROJECT_NAME) from_command_line = False change_uid_msg = "You should not run this command as root" @@ -24,8 +23,11 @@ change_uid_msg = "You should not run this command as root" def cli(): global from_command_line from_command_line = True + command = " ".join(sys.argv) change_working_directory() + logger = setup_logging() or logging.getLogger(bench.PROJECT_NAME) + logger.info(command) check_uid() change_dir() change_uid() @@ -56,7 +58,8 @@ def cli(): try: bench_command() - except PatchError: + except BaseException as e: + logger.warn("{0} executed with exit code {1}".format(command, getattr(e, "code", None))) sys.exit(1) diff --git a/bench/commands/__init__.py b/bench/commands/__init__.py index 8ee317d9..2b073b65 100755 --- a/bench/commands/__init__.py +++ b/bench/commands/__init__.py @@ -14,10 +14,7 @@ def print_bench_version(ctx, param, value): @click.option('--version', is_flag=True, is_eager=True, callback=print_bench_version, expose_value=False) def bench_command(bench_path='.'): import bench - from bench.utils import setup_logging - bench.set_frappe_version(bench_path=bench_path) - setup_logging(bench_path=bench_path) from bench.commands.make import init, get_app, new_app, remove_app, exclude_app_for_update, include_app_for_update, pip diff --git a/bench/utils.py b/bench/utils.py index 5740d50a..89f0acee 100755 --- a/bench/utils.py +++ b/bench/utils.py @@ -39,7 +39,7 @@ class PatchError(Exception): class CommandFailedError(Exception): pass -logger = logging.getLogger(__name__) +logger = logging.getLogger(bench.PROJECT_NAME) bench_cache_file = '.bench.cmd' folders_in_bench = ('apps', 'sites', 'config', 'logs', 'config/pids') sudoers_file = '/etc/sudoers.d/frappe' @@ -139,7 +139,7 @@ def init(path, apps_path=None, no_procfile=False, no_backups=False, if e.errno == errno.EEXIST: pass - setup_logging() + setup_logging(bench_path=path) setup_env(bench_path=path, python=python) @@ -297,8 +297,13 @@ def clone_apps_from(bench_path, clone_from, update_app=True): def exec_cmd(cmd, cwd='.'): import shlex print("{0}$ {1}{2}".format(color.silver, cmd, color.nc)) + cwd_info = "cd {0} && ".format(cwd) if cwd != "." else "" + cmd_log = "{0}{1}".format(cwd_info, cmd) + logger.debug(cmd_log) cmd = shlex.split(cmd) - return subprocess.call(cmd, cwd=cwd, universal_newlines=True) + return_code = subprocess.call(cmd, cwd=cwd, universal_newlines=True) + if return_code: + logger.warn("{0} executed with exit code {1}".format(cmd_log, return_code)) def which(executable, raise_err = False): @@ -372,7 +377,7 @@ def get_sites(bench_path='.'): def setup_backups(bench_path='.'): from bench.config.common_site_config import get_config - logger.info('setting up backups') + logger.log('setting up backups') bench_dir = os.path.abspath(bench_path) user = get_config(bench_path=bench_dir).get('frappe_user') @@ -424,15 +429,37 @@ def setup_sudoers(user): def setup_logging(bench_path='.'): + LOG_LEVEL = 15 + logging.addLevelName(LOG_LEVEL, "LOG") + def logv(self, message, *args, **kws): + if self.isEnabledFor(LOG_LEVEL): + self._log(LOG_LEVEL, message, args, **kws) + logging.Logger.log = logv + + class log_filter(object): + def __init__(self, level): + self.__level = level + + def filter(self, logRecord): + return logRecord.levelno == self.__level + if os.path.exists(os.path.join(bench_path, 'logs')): logger = logging.getLogger(bench.PROJECT_NAME) log_file = os.path.join(bench_path, 'logs', 'bench.log') formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s') hdlr = logging.FileHandler(log_file) hdlr.setFormatter(formatter) + + log_hndlr = logging.StreamHandler(sys.stdout) + log_hndlr.setFormatter(logging.Formatter('%(message)s')) + log_hndlr.addFilter(log_filter(LOG_LEVEL)) + logger.addHandler(hdlr) + logger.addHandler(log_hndlr) logger.setLevel(logging.DEBUG) + return logger + def get_process_manager(): for proc_man in ['honcho', 'foreman', 'forego']: @@ -1081,9 +1108,9 @@ def migrate_env(python, backup=False): redis = '{redis} -p {port}'.format(redis=which('redis-cli'), port=rredis.port) - logger.debug('Clearing Redis Cache...') + logger.log('Clearing Redis Cache...') exec_cmd('{redis} FLUSHALL'.format(redis = redis)) - logger.debug('Clearing Redis DataBase...') + logger.log('Clearing Redis DataBase...') exec_cmd('{redis} FLUSHDB'.format(redis = redis)) except: logger.warn('Please ensure Redis Connections are running or Daemonized.') @@ -1097,7 +1124,7 @@ def migrate_env(python, backup=False): source = os.path.join(path, 'env') target = parch - logger.debug('Backing up Virtual Environment') + logger.log('Backing up Virtual Environment') stamp = datetime.now().strftime('%Y%m%d_%H%M%S') dest = os.path.join(path, str(stamp)) @@ -1105,17 +1132,18 @@ def migrate_env(python, backup=False): shutil.move(dest, target) # Create virtualenv using specified python + venv_creation, packages_setup = 1, 1 try: - logger.debug('Setting up a New Virtual {} Environment'.format(python)) - exec_cmd('{virtualenv} --python {python} {pvenv}'.format(virtualenv=virtualenv, python=python, pvenv=pvenv)) + logger.log('Setting up a New Virtual {} Environment'.format(python)) + venv_creation = exec_cmd('{virtualenv} --python {python} {pvenv}'.format(virtualenv=virtualenv, python=python, pvenv=pvenv)) apps = ' '.join(["-e {}".format(os.path.join("apps", app)) for app in get_apps()]) - exec_cmd('{0} install -q -U {1}'.format(pip, apps)) + packages_setup = exec_cmd('{0} install -q -U {1}'.format(pip, apps)) - logger.debug('Migration Successful to {}'.format(python)) + logger.log('Migration Successful to {}'.format(python)) except: - logger.debug('Migration Error') - raise + if venv_creation or packages_setup: + logger.warn('Migration Error') def is_dist_editable(dist):