From 9a23725ce0f6bf79eedf7af72a96090ce51ab1c4 Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Thu, 25 Jun 2020 00:09:19 +0300 Subject: [PATCH 01/10] log: Add BASH_IT_LOG_PREFIX option Also add a new test to check it --- DEVELOPMENT.md | 7 +++++++ lib/log.bash | 5 +++-- test/lib/log.bats | 7 +++++++ 3 files changed, 17 insertions(+), 2 deletions(-) diff --git a/DEVELOPMENT.md b/DEVELOPMENT.md index 5328cc78d7..e2fc7bd564 100644 --- a/DEVELOPMENT.md +++ b/DEVELOPMENT.md @@ -4,12 +4,19 @@ This page summarizes a couple of rules to keep in mind when developing features ## Debugging and Logging +### General Logging + While developing feature or making changes in general, you can log error/warning/debug using `_log_error` `_log_warning` and `_log_debug`. This will help you solve problems quicker and also propagate important notes to other users of Bash-it. You can see the logs by using `bash-it doctor` command to reload and see the logs. Alternatively, you can set `BASH_IT_LOG_LEVEL` to `BASH_IT_LOG_LEVEL_ERROR`, `BASH_IT_LOG_LEVEL_WARNING` or `BASH_IT_LOG_LEVEL_ALL`. +### Log Prefix/Context + +You can define `BASH_IT_LOG_PREFIX` in your files in order to a have a constant prefix before your logs. +Note that we prefer to uses "tags" based logging, i.e `plugins: git: DEBUG: Loading git plugin`. + ## Load Order diff --git a/lib/log.bash b/lib/log.bash index 8f954359d2..afc6b1ac74 100644 --- a/lib/log.bash +++ b/lib/log.bash @@ -6,12 +6,13 @@ export BASH_IT_LOG_LEVEL_ALL=3 function _log_general() { - _about 'Internal function used for logging' + _about 'Internal function used for logging, uses BASH_IT_LOG_PREFIX as a prefix' _param '1: color of the message' _param '2: message to log' _group 'log' - _has_colors && echo -e "$1$2${echo_normal}" || echo -e "$2" + message=${BASH_IT_LOG_PREFIX}$2 + _has_colors && echo -e "$1${message}${echo_normal}" || echo -e "${message}" } function _log_debug() diff --git a/test/lib/log.bats b/test/lib/log.bats index da31a9b519..ad1cdf07ae 100644 --- a/test/lib/log.bats +++ b/test/lib/log.bats @@ -77,3 +77,10 @@ load ../../lib/log run _log_error "test test test" refute_output } + +@test "lib log: logging with prefix" { + BASH_IT_LOG_LEVEL=$BASH_IT_LOG_LEVEL_ALL + BASH_IT_LOG_PREFIX="nice: prefix: " + run _log_debug "test test test" + assert_output "nice: prefix: DEBUG: test test test" +} From 453c17de3dd344163fb9502f805f9feda2fa9220 Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Thu, 25 Jun 2020 00:45:24 +0300 Subject: [PATCH 02/10] bash-it: Add logs to bash-it.sh --- bash_it.sh | 28 +++++++++++++++++++++++++--- 1 file changed, 25 insertions(+), 3 deletions(-) diff --git a/bash_it.sh b/bash_it.sh index ab911019ba..fec92c8d6b 100755 --- a/bash_it.sh +++ b/bash_it.sh @@ -1,11 +1,12 @@ #!/usr/bin/env bash # Initialize Bash It +BASH_IT_LOG_PREFIX="core: main: " # Only set $BASH_IT if it's not already set if [ -z "$BASH_IT" ]; then # Setting $BASH to maintain backwards compatibility - # TODO: warn users that they should upgrade their .bash_profile + _log_warning "BASH_IT variable not initialized, please upgrade your bash-it version and reinstall it!" export BASH_IT=$BASH BASH="$(bash -c 'echo $BASH')" export BASH @@ -14,11 +15,12 @@ fi # For backwards compatibility, look in old BASH_THEME location if [ -z "$BASH_IT_THEME" ]; then - # TODO: warn users that they should upgrade their .bash_profile + _log_warning "BASH_IT_THEME variable not initialized, please upgrade your bash-it version and reinstall it!" export BASH_IT_THEME="$BASH_THEME"; unset BASH_THEME; fi +_log_debug "Loading composure..." # Load composure first, so we support function metadata # shellcheck source=./lib/composure.bash source "${BASH_IT}/lib/composure.bash" @@ -27,11 +29,16 @@ source "${BASH_IT}/lib/composure.bash" cite _about _param _example _group _author _version # libraries, but skip appearance (themes) for now +_log_debug "Loading libraries(except appearance)..." LIB="${BASH_IT}/lib/*.bash" APPEARANCE_LIB="${BASH_IT}/lib/appearance.bash" for _bash_it_config_file in $LIB do if [ "$_bash_it_config_file" != "$APPEARANCE_LIB" ]; then + filename=${_bash_it_config_file##*/} + filename=${filename%.bash} + BASH_IT_LOG_PREFIX="lib: ${filename}: " + _log_debug "Loading library file..." # shellcheck disable=SC1090 source "$_bash_it_config_file" fi @@ -51,36 +58,51 @@ done # Load theme, if a theme was set if [[ ! -z "${BASH_IT_THEME}" ]]; then + _log_debug "Loading \"${BASH_IT_THEME}\" theme..." # Load colors and helpers first so they can be used in base theme + BASH_IT_LOG_PREFIX="themes: colors: " # shellcheck source=./themes/colors.theme.bash source "${BASH_IT}/themes/colors.theme.bash" + BASH_IT_LOG_PREFIX="themes: githelpers: " # shellcheck source=./themes/githelpers.theme.bash source "${BASH_IT}/themes/githelpers.theme.bash" + BASH_IT_LOG_PREFIX="themes: p4helpers: " # shellcheck source=./themes/p4helpers.theme.bash source "${BASH_IT}/themes/p4helpers.theme.bash" + BASH_IT_LOG_PREFIX="themes: base: " # shellcheck source=./themes/base.theme.bash source "${BASH_IT}/themes/base.theme.bash" + BASH_IT_LOG_PREFIX="lib: appearance: " # appearance (themes) now, after all dependencies # shellcheck source=./lib/appearance.bash source "$APPEARANCE_LIB" fi -# Load custom aliases, completion, plugins +BASH_IT_LOG_PREFIX="core: main: " +_log_debug "Loading custom aliases, completion, plugins..." for file_type in "aliases" "completion" "plugins" do if [ -e "${BASH_IT}/${file_type}/custom.${file_type}.bash" ] then + BASH_IT_LOG_PREFIX="${file_type}: custom: " + _log_debug "Loading component..." # shellcheck disable=SC1090 source "${BASH_IT}/${file_type}/custom.${file_type}.bash" fi done # Custom +BASH_IT_LOG_PREFIX="core: main: " +_log_debug "Loading general custom files..." CUSTOM="${BASH_IT_CUSTOM:=${BASH_IT}/custom}/*.bash ${BASH_IT_CUSTOM:=${BASH_IT}/custom}/**/*.bash" for _bash_it_config_file in $CUSTOM do if [ -e "${_bash_it_config_file}" ]; then + filename=$(basename "${_bash_it_config_file}") + filename=${filename%*.bash} + BASH_IT_LOG_PREFIX="custom: $filename" + _log_debug "Loading custom file..." # shellcheck disable=SC1090 source "$_bash_it_config_file" fi From 6a4142ced7562716c96e82844fb62800e6230d2a Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Thu, 25 Jun 2020 00:57:02 +0300 Subject: [PATCH 03/10] scripts: Add logs to reloader.bash --- scripts/reloader.bash | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/scripts/reloader.bash b/scripts/reloader.bash index b0fe7e41fe..9563e5259d 100644 --- a/scripts/reloader.bash +++ b/scripts/reloader.bash @@ -1,15 +1,26 @@ #!/bin/bash +BASH_IT_LOG_PREFIX="core: reloader: " pushd "${BASH_IT}" >/dev/null || exit 1 -# TODO: Add debugging output +function _set-prefix-based-on-path() +{ + filename=$(_bash-it-get-component-name-from-path "$1") + extension=$(_bash-it-get-component-type-from-path "$1") + BASH_IT_LOG_PREFIX="$extension: $filename: " +} if [ "$1" != "skip" ] && [ -d "./enabled" ]; then _bash_it_config_type="" if [[ "${1}" =~ ^(alias|completion|plugin)$ ]]; then _bash_it_config_type=$1 + _log_debug "Loading enabled $1 components..." + else + _log_debug "Loading all enabled components..." fi for _bash_it_config_file in $(sort <(compgen -G "./enabled/*${_bash_it_config_type}.bash")); do if [ -e "${_bash_it_config_file}" ]; then + _set-prefix-based-on-path "${_bash_it_config_file}" + _log_debug "Loading component..." # shellcheck source=/dev/null source $_bash_it_config_file else @@ -20,9 +31,11 @@ fi if [ ! -z "${2}" ] && [[ "${2}" =~ ^(aliases|completion|plugins)$ ]] && [ -d "${2}/enabled" ]; then - # TODO: We should warn users they're using legacy enabling + _log_warning "Using legacy enabling for $2, please update your bash-it version and migrate" for _bash_it_config_file in $(sort <(compgen -G "./${2}/enabled/*.bash")); do if [ -e "$_bash_it_config_file" ]; then + _set-prefix-based-on-path "${_bash_it_config_file}" + _log_debug "Loading component..." # shellcheck source=/dev/null source "$_bash_it_config_file" else From 5daecc9381e2a7d881b0d220e2aa774f4d31a7ab Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Thu, 25 Jun 2020 01:36:12 +0300 Subject: [PATCH 04/10] lib: Log in case _command_exists fails --- lib/helpers.bash | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/helpers.bash b/lib/helpers.bash index 2d05c91959..2459e02b0d 100644 --- a/lib/helpers.bash +++ b/lib/helpers.bash @@ -21,7 +21,7 @@ function _command_exists () _param '1: command to check' _example '$ _command_exists ls && echo exists' _group 'lib' - type "$1" &> /dev/null ; + type "$1" &> /dev/null || (_log_warning "Command $1 does not exist!" && return 1) ; } function _make_reload_alias() { From 8a3cf763074309647fa4f5615af2c5a54fedbb19 Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Sat, 27 Jun 2020 14:01:47 +0300 Subject: [PATCH 05/10] lib: Move _has_colors to log module --- lib/appearance.bash | 10 ---------- lib/log.bash | 10 ++++++++++ 2 files changed, 10 insertions(+), 10 deletions(-) diff --git a/lib/appearance.bash b/lib/appearance.bash index d684332f6c..6d0ef2ffce 100644 --- a/lib/appearance.bash +++ b/lib/appearance.bash @@ -1,15 +1,5 @@ #!/usr/bin/env bash -function _has_colors() -{ - # Check that stdout is a terminal - test -t 1 || return 1 - - ncolors=$(tput colors) - test -n "$ncolors" && test "$ncolors" -ge 8 || return 1 - return 0 -} - # colored ls export LSCOLORS='Gxfxcxdxdxegedabagacad' diff --git a/lib/log.bash b/lib/log.bash index afc6b1ac74..856ec9aa43 100644 --- a/lib/log.bash +++ b/lib/log.bash @@ -4,6 +4,16 @@ export BASH_IT_LOG_LEVEL_ERROR=1 export BASH_IT_LOG_LEVEL_WARNING=2 export BASH_IT_LOG_LEVEL_ALL=3 +function _has_colors() +{ + # Check that stdout is a terminal + test -t 1 || return 1 + + ncolors=$(tput colors) + test -n "$ncolors" && test "$ncolors" -ge 8 || return 1 + return 0 +} + function _log_general() { _about 'Internal function used for logging, uses BASH_IT_LOG_PREFIX as a prefix' From 811c9ecd716382df14f1a6e03ddf3eee1b5d6693 Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Sat, 27 Jun 2020 14:02:20 +0300 Subject: [PATCH 06/10] bash-it: Reorder main bash-it.sh so logs can happen --- bash_it.sh | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/bash_it.sh b/bash_it.sh index fec92c8d6b..8a277bed1c 100755 --- a/bash_it.sh +++ b/bash_it.sh @@ -6,12 +6,22 @@ BASH_IT_LOG_PREFIX="core: main: " if [ -z "$BASH_IT" ]; then # Setting $BASH to maintain backwards compatibility - _log_warning "BASH_IT variable not initialized, please upgrade your bash-it version and reinstall it!" export BASH_IT=$BASH BASH="$(bash -c 'echo $BASH')" export BASH + BASH_IT_OLD_BASH_SETUP=true fi +# Load composure first, so we support function metadata +# shellcheck source=./lib/composure.bash +source "${BASH_IT}/lib/composure.bash" +# We need to load logging module first as well in order to be able to log +# shellcheck source=./lib/log.bash +source "${BASH_IT}/lib/log.bash" + +# We can only log it now +[ -z "$BASH_IT_OLD_BASH_SETUP" ] || _log_warning "BASH_IT variable not initialized, please upgrade your bash-it version and reinstall it!" + # For backwards compatibility, look in old BASH_THEME location if [ -z "$BASH_IT_THEME" ]; then @@ -20,11 +30,6 @@ then unset BASH_THEME; fi -_log_debug "Loading composure..." -# Load composure first, so we support function metadata -# shellcheck source=./lib/composure.bash -source "${BASH_IT}/lib/composure.bash" - # support 'plumbing' metadata cite _about _param _example _group _author _version From 8d9f81fce09eb248885dad903bcf61d0fe614514 Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Sat, 27 Jun 2020 15:28:47 +0300 Subject: [PATCH 07/10] lib: Add get-component-name/type-from-path --- lib/utilities.bash | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/lib/utilities.bash b/lib/utilities.bash index 7994a731b5..db63956d74 100644 --- a/lib/utilities.bash +++ b/lib/utilities.bash @@ -6,6 +6,24 @@ # Generic utilies ########################################################################### +_bash-it-get-component-name-from-path() { + # filename without path + filename=${1##*/} + # filename without path or priority + filename=${filename##*---} + # filename without path, priority or extension + echo ${filename%.*.bash} +} + +_bash-it-get-component-type-from-path() { + # filename without path + filename=${1##*/} + # filename without path or priority + filename=${filename##*---} + # extension + echo ${filename} | cut -d '.' -f 2 +} + # This function searches an array for an exact match against the term passed # as the first argument to the function. This function exits as soon as # a match is found. From e6ebcda6086faef4929302be76cb4b2ac6e7a21f Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Sun, 28 Jun 2020 11:14:30 +0300 Subject: [PATCH 08/10] log: Fix logging to comply with the tests --- lib/log.bash | 38 ++++++++++++++++----------------- test/themes/base.theme.git.bats | 1 + 2 files changed, 20 insertions(+), 19 deletions(-) diff --git a/lib/log.bash b/lib/log.bash index 856ec9aa43..882bc5f9a4 100644 --- a/lib/log.bash +++ b/lib/log.bash @@ -16,10 +16,10 @@ function _has_colors() function _log_general() { - _about 'Internal function used for logging, uses BASH_IT_LOG_PREFIX as a prefix' - _param '1: color of the message' - _param '2: message to log' - _group 'log' + about 'Internal function used for logging, uses BASH_IT_LOG_PREFIX as a prefix' + param '1: color of the message' + param '2: message to log' + group 'log' message=${BASH_IT_LOG_PREFIX}$2 _has_colors && echo -e "$1${message}${echo_normal}" || echo -e "${message}" @@ -27,33 +27,33 @@ function _log_general() function _log_debug() { - _about 'log a debug message by echoing to the screen. needs BASH_IT_LOG_LEVEL >= BASH_IT_LOG_LEVEL_ALL' - _param '1: message to log' - _example '$ _log_debug "Loading plugin git..."' - _group 'log' + about 'log a debug message by echoing to the screen. needs BASH_IT_LOG_LEVEL >= BASH_IT_LOG_LEVEL_ALL' + param '1: message to log' + example '$ _log_debug "Loading plugin git..."' + group 'log' - [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_ALL ]] || return + [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_ALL ]] || return 0 _log_general "${echo_green}" "DEBUG: $1" } function _log_warning() { - _about 'log a message by echoing to the screen. needs BASH_IT_LOG_LEVEL >= BASH_IT_LOG_LEVEL_WARNING' - _param '1: message to log' - _example '$ _log_warning "git binary not found, disabling git plugin..."' - _group 'log' + about 'log a message by echoing to the screen. needs BASH_IT_LOG_LEVEL >= BASH_IT_LOG_LEVEL_WARNING' + param '1: message to log' + example '$ _log_warning "git binary not found, disabling git plugin..."' + group 'log' - [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_WARNING ]] || return + [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_WARNING ]] || return 0 _log_general "${echo_yellow}" " WARN: $1" } function _log_error() { - _about 'log a message by echoing to the screen. needs BASH_IT_LOG_LEVEL >= BASH_IT_LOG_LEVEL_ERROR' - _param '1: message to log' - _example '$ _log_error "Failed to load git plugin..."' - _group 'log' + about 'log a message by echoing to the screen. needs BASH_IT_LOG_LEVEL >= BASH_IT_LOG_LEVEL_ERROR' + param '1: message to log' + example '$ _log_error "Failed to load git plugin..."' + group 'log' - [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_ERROR ]] || return + [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_ERROR ]] || return 0 _log_general "${echo_red}" "ERROR: $1" } diff --git a/test/themes/base.theme.git.bats b/test/themes/base.theme.git.bats index 940121cc4c..ce86d2a1a3 100644 --- a/test/themes/base.theme.git.bats +++ b/test/themes/base.theme.git.bats @@ -2,6 +2,7 @@ load ../test_helper load ../../lib/composure +load ../../lib/log cite _about _param _example _group _author _version From 3069af37e0b2ad1c600167780b383c78b4ca606b Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Sun, 28 Jun 2020 11:15:00 +0300 Subject: [PATCH 09/10] tests: Include lib log --- test/lib/helpers.bats | 1 + test/themes/base.theme.bats | 1 + test/themes/base.theme.svn.bats | 1 + 3 files changed, 3 insertions(+) diff --git a/test/lib/helpers.bats b/test/lib/helpers.bats index c3f905e7f2..e452c38eae 100644 --- a/test/lib/helpers.bats +++ b/test/lib/helpers.bats @@ -2,6 +2,7 @@ load ../test_helper load ../../lib/composure +load ../../lib/log load ../../lib/utilities load ../../lib/search load ../../plugins/available/base.plugin diff --git a/test/themes/base.theme.bats b/test/themes/base.theme.bats index 2cf809dc1d..aa64904a63 100644 --- a/test/themes/base.theme.bats +++ b/test/themes/base.theme.bats @@ -2,6 +2,7 @@ load ../test_helper load ../../lib/composure +load ../../lib/log cite _about _param _example _group _author _version diff --git a/test/themes/base.theme.svn.bats b/test/themes/base.theme.svn.bats index 89279d1b16..b797da02b4 100644 --- a/test/themes/base.theme.svn.bats +++ b/test/themes/base.theme.svn.bats @@ -2,6 +2,7 @@ load ../test_helper load ../../lib/composure +load ../../lib/log cite _about _param _example _group _author _version From 72dbfd24805c6323df02d92e932ac2c37fdd2c88 Mon Sep 17 00:00:00 2001 From: Noah Gorny Date: Thu, 2 Jul 2020 13:52:02 +0300 Subject: [PATCH 10/10] lib: log: Insert log level before message prefix Also fix tests accordinly --- lib/log.bash | 11 ++++++----- test/lib/log.bats | 2 +- 2 files changed, 7 insertions(+), 6 deletions(-) diff --git a/lib/log.bash b/lib/log.bash index 882bc5f9a4..105c9064a1 100644 --- a/lib/log.bash +++ b/lib/log.bash @@ -18,10 +18,11 @@ function _log_general() { about 'Internal function used for logging, uses BASH_IT_LOG_PREFIX as a prefix' param '1: color of the message' - param '2: message to log' + param '2: log level to print before the prefix' + param '3: message to log' group 'log' - message=${BASH_IT_LOG_PREFIX}$2 + message=$2${BASH_IT_LOG_PREFIX}$3 _has_colors && echo -e "$1${message}${echo_normal}" || echo -e "${message}" } @@ -33,7 +34,7 @@ function _log_debug() group 'log' [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_ALL ]] || return 0 - _log_general "${echo_green}" "DEBUG: $1" + _log_general "${echo_green}" "DEBUG: " "$1" } function _log_warning() @@ -44,7 +45,7 @@ function _log_warning() group 'log' [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_WARNING ]] || return 0 - _log_general "${echo_yellow}" " WARN: $1" + _log_general "${echo_yellow}" " WARN: " "$1" } function _log_error() @@ -55,5 +56,5 @@ function _log_error() group 'log' [[ "$BASH_IT_LOG_LEVEL" -ge $BASH_IT_LOG_LEVEL_ERROR ]] || return 0 - _log_general "${echo_red}" "ERROR: $1" + _log_general "${echo_red}" "ERROR: " "$1" } diff --git a/test/lib/log.bats b/test/lib/log.bats index ad1cdf07ae..5afb9195da 100644 --- a/test/lib/log.bats +++ b/test/lib/log.bats @@ -82,5 +82,5 @@ load ../../lib/log BASH_IT_LOG_LEVEL=$BASH_IT_LOG_LEVEL_ALL BASH_IT_LOG_PREFIX="nice: prefix: " run _log_debug "test test test" - assert_output "nice: prefix: DEBUG: test test test" + assert_output "DEBUG: nice: prefix: test test test" }