From 096fbf2145c93b0967bd23f45efa33275bacb1e8 Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Sun, 27 Sep 2020 01:14:17 +0000 Subject: [PATCH 1/7] Introduce Diagnostic Mode MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Diagnostic mode is intended to be used for rebar3 maintainers to debug and understand issues. It shows all the things and all the data and works with the assumption that people has intent to use the source code to debug things. Debug mode is promoted to user-oriented debugging, based on the idea that what they care about is figuring out their interactions with the tool. A major improvement in usability would be to directly tie the user config to the interpreted config (ie merged profiles) to clearly hint at seen rebar3’s behaviour. If the debug output can show that and even tie some behaviours to the config value that impacts things, we could get some discoverability out of it too, something missing from declarative tools like this. --- src/rebar.hrl | 1 + src/rebar3.erl | 14 +++++++++----- src/rebar_log.erl | 42 +++++++++++++++++++++++++++++++++++++++--- 3 files changed, 49 insertions(+), 8 deletions(-) diff --git a/src/rebar.hrl b/src/rebar.hrl index c03a2c8f..65b845d9 100644 --- a/src/rebar.hrl +++ b/src/rebar.hrl @@ -6,6 +6,7 @@ -define(CONSOLE(Str, Args), io:format(Str++"~n", Args)). +-define(DIAGNOSTIC(Str, Args), rebar_log:log(diagnostic, Str, Args)). -define(DEBUG(Str, Args), rebar_log:log(debug, Str, Args)). -define(INFO(Str, Args), rebar_log:log(info, Str, Args)). -define(WARN(Str, Args), rebar_log:log(warn, Str, Args)). diff --git a/src/rebar3.erl b/src/rebar3.erl index 44c07c3c..d830a303 100644 --- a/src/rebar3.erl +++ b/src/rebar3.erl @@ -283,12 +283,16 @@ set_options(State, {Options, NonOptArgs}) -> log_level() -> case os:getenv("QUIET") of Q when Q == false; Q == "" -> - DefaultLevel = rebar_log:default_level(), - case os:getenv("DEBUG") of - D when D == false; D == "" -> - DefaultLevel; + case os:getenv("DIAGNOSTIC") of + Di when Di == false; Di == "" -> + case os:getenv("DEBUG") of + D when D == false; D == "" -> + rebar_log:default_level(); + _ -> + rebar_log:debug_level() + end; _ -> - DefaultLevel + 3 + rebar_log:diagnostic_level() end; _ -> rebar_log:error_level() diff --git a/src/rebar_log.erl b/src/rebar_log.erl index 7fc2312f..6a985703 100644 --- a/src/rebar_log.erl +++ b/src/rebar_log.erl @@ -32,15 +32,19 @@ get_level/0, error_level/0, default_level/0, + debug_level/0, + diagnostic_level/0, intensity/0, log/3, is_verbose/1, - valid_level/1]). + valid_level/1, + truncate/1]). -define(ERROR_LEVEL, 0). -define(WARN_LEVEL, 1). -define(INFO_LEVEL, 2). -define(DEBUG_LEVEL, 3). +-define(DIAGNOSTIC_LEVEL, 4). -define(DFLT_INTENSITY, high). %% =================================================================== @@ -73,7 +77,8 @@ init(Caller, Verbosity) -> ?ERROR_LEVEL -> error; ?WARN_LEVEL -> warn; ?INFO_LEVEL -> info; - ?DEBUG_LEVEL -> debug + ?DEBUG_LEVEL -> debug; + ?DIAGNOSTIC_LEVEL -> debug end, Intensity = intensity(), application:set_env(rebar, log_caller, Caller), @@ -92,6 +97,17 @@ get_level() -> Level end. +log(diagnostic, Str, Args) -> + %% The diagnostic level is intended for debug info + %% that is useful for rebar3 developers and implementers who + %% understand the internal structure; the debug level + %% itself should aim to be useful for users themselves. + %% The underlying library only supports debug at its lowest + %% level, so we filter on our end of the lib. + case get_level() of + ?DIAGNOSTIC_LEVEL -> log(debug, Str, Args); + _ -> ok + end; log(Level = error, Str, Args) -> case application:get_env(rebar, log) of {ok, LogState} -> @@ -118,13 +134,33 @@ crashdump(File, Str, Args) -> error_level() -> ?ERROR_LEVEL. default_level() -> ?INFO_LEVEL. +debug_level() -> ?DEBUG_LEVEL. +diagnostic_level() -> ?DIAGNOSTIC_LEVEL. is_verbose(State) -> rebar_state:get(State, is_verbose, false). valid_level(Level) -> - erlang:max(?ERROR_LEVEL, erlang:min(Level, ?DEBUG_LEVEL)). + erlang:max(?ERROR_LEVEL, erlang:min(Level, ?DIAGNOSTIC_LEVEL)). %% =================================================================== %% Internal functions %% =================================================================== +truncate(IoData) -> + Size = iolist_size(IoData), + if Size > 4096 -> [take_bytes(4096, IoData), "[...]"]; + Size =< 4096 -> IoData + end. + +take_bytes(0, _) -> []; +take_bytes(N, Bin) when is_binary(Bin), byte_size(Bin) > N -> + <> = Bin, + binary:copy(B); % avoid holding on to large refs +take_bytes(_, Bin) when is_binary(Bin) -> + Bin; +take_bytes(_, []) -> []; +take_bytes(N, [H|T]) when is_integer(H) -> + [H | take_bytes(N-1, T)]; +take_bytes(N, [H|T]) when is_binary(H); is_list(H) -> + Res = take_bytes(N, H), + [Res | take_bytes(N-byte_size(Res), T)]. From aa0043f1f84327502009383a611fb2899e566c45 Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Sun, 27 Sep 2020 01:26:18 +0000 Subject: [PATCH 2/7] Rename ?FAIL to ?ABORT The change was possible since R13B04 when macros with many arities became supported. We never really cleaned that stuff up before so I'm picking it up while I'm updating that code --- src/rebar.hrl | 5 +---- src/rebar_api.erl | 2 +- src/rebar_base_compiler.erl | 2 +- src/rebar_compiler.erl | 6 +++--- src/rebar_compiler_dag.erl | 2 +- src/rebar_compiler_mib.erl | 2 +- src/rebar_erlc_compiler.erl | 2 +- src/rebar_file_utils.erl | 2 +- src/rebar_parallel.erl | 2 +- src/rebar_prv_install_deps.erl | 3 ++- 10 files changed, 13 insertions(+), 15 deletions(-) diff --git a/src/rebar.hrl b/src/rebar.hrl index 65b845d9..12629fc4 100644 --- a/src/rebar.hrl +++ b/src/rebar.hrl @@ -1,7 +1,4 @@ -%% TODO: rename FAIL to ABORT once we require at least R13B04 for -%% building rebar. Macros with different arity were not supported by the -%% compiler before 13B04. --define(FAIL, rebar_utils:abort()). +-define(ABORT, rebar_utils:abort()). -define(ABORT(Str, Args), rebar_utils:abort(Str, Args)). -define(CONSOLE(Str, Args), io:format(Str++"~n", Args)). diff --git a/src/rebar_api.erl b/src/rebar_api.erl index 00eb0541..cbb4b699 100644 --- a/src/rebar_api.erl +++ b/src/rebar_api.erl @@ -24,7 +24,7 @@ %% @doc Interrupts program flow -spec abort() -> no_return(). -abort() -> ?FAIL. +abort() -> ?ABORT. %% @doc like {@link error/2}, except it also raises an %% exception to interrupt program flow. diff --git a/src/rebar_base_compiler.erl b/src/rebar_base_compiler.erl index ad81c86c..56589197 100644 --- a/src/rebar_base_compiler.erl +++ b/src/rebar_base_compiler.erl @@ -195,7 +195,7 @@ compile_each([Source | Rest], Config, CompileFn) -> ?ERROR("Compiling ~ts failed", [NewSource]), maybe_report(Error), ?DEBUG("Compilation failed: ~p", [Error]), - ?FAIL + ?ABORT end, compile_each(Rest, Config, CompileFn). diff --git a/src/rebar_compiler.erl b/src/rebar_compiler.erl index 6ec8d2d4..e718eb41 100644 --- a/src/rebar_compiler.erl +++ b/src/rebar_compiler.erl @@ -272,7 +272,7 @@ do_compile(CompilerMod, Source, Outs, Config, Opts) -> ?ERROR("Compiling ~ts failed", [NewSource]), maybe_report(Error), ?DEBUG("Compilation failed: ~p", [Error]), - ?FAIL + ?ABORT end. do_compile_and_track(CompilerMod, Source, Outs, Config, Opts) -> @@ -292,7 +292,7 @@ do_compile_and_track(CompilerMod, Source, Outs, Config, Opts) -> ?ERROR("Compiling ~ts failed", [NewSource]), maybe_report(Error), ?DEBUG("Compilation failed: ~p", [Error]), - ?FAIL + ?ABORT end. store_artifacts(_G, []) -> @@ -341,7 +341,7 @@ compile_handler({Error, Source}, [Config | _Rest]) -> NewSource = format_error_source(Source, Config), ?ERROR("Compiling ~ts failed", [NewSource]), maybe_report(Error), - ?FAIL. + ?ABORT. clean_(CompilerMod, AppInfo, _Label) -> #{src_dirs := SrcDirs, diff --git a/src/rebar_compiler_dag.erl b/src/rebar_compiler_dag.erl index 74e97984..ef01523a 100644 --- a/src/rebar_compiler_dag.erl +++ b/src/rebar_compiler_dag.erl @@ -134,7 +134,7 @@ finalise_populate_sources(G, InDirs, Waiting) -> {'DOWN', _MRef, process, Pid, Reason} -> {_Status, Source} = maps:get(Pid, Waiting), ?ERROR("Failed to get dependencies for ~s~n~p", [Source, Reason]), - ?FAIL + ?ABORT end. %% @doc this function scans all the source files found and looks into diff --git a/src/rebar_compiler_mib.erl b/src/rebar_compiler_mib.erl index e25cc809..e5db42bb 100644 --- a/src/rebar_compiler_mib.erl +++ b/src/rebar_compiler_mib.erl @@ -91,7 +91,7 @@ compile(Source, OutDirs, _, Opts) -> rebar_file_utils:mv(HrlFilename, HrlOut), ok; {error, compilation_failed} -> - ?FAIL + ?ABORT end. clean(MibFiles, AppInfo) -> diff --git a/src/rebar_erlc_compiler.erl b/src/rebar_erlc_compiler.erl index b9dc60af..1b996b32 100644 --- a/src/rebar_erlc_compiler.erl +++ b/src/rebar_erlc_compiler.erl @@ -620,7 +620,7 @@ compile_mib(AppInfo) -> rebar_file_utils:mv(HrlFilename, AppInclude), ok; {error, compilation_failed} -> - ?FAIL + ?ABORT end end. diff --git a/src/rebar_file_utils.erl b/src/rebar_file_utils.erl index ebbd5e99..f01c9d32 100644 --- a/src/rebar_file_utils.erl +++ b/src/rebar_file_utils.erl @@ -366,7 +366,7 @@ delete_each([File | Rest]) -> delete_each(Rest); {error, Reason} -> ?ERROR("Failed to delete file ~ts: ~p\n", [File, Reason]), - ?FAIL + ?ABORT end. %% @doc backwards compat layer to pre-utf8 support diff --git a/src/rebar_parallel.erl b/src/rebar_parallel.erl index e443619c..8e48c9b7 100644 --- a/src/rebar_parallel.erl +++ b/src/rebar_parallel.erl @@ -34,7 +34,7 @@ parallel_dispatch(Targets, Pids, Handler, Args) -> parallel_dispatch(Targets, NewPids, Handler, Args); {'DOWN', _Mref, _, _Pid, Info} -> ?ERROR("Task failed: ~p", [Info]), - ?FAIL; + ?ABORT; {result, Result} -> case Handler(Result, Args) of ok -> diff --git a/src/rebar_prv_install_deps.erl b/src/rebar_prv_install_deps.erl index 4bd58057..52c57156 100644 --- a/src/rebar_prv_install_deps.erl +++ b/src/rebar_prv_install_deps.erl @@ -429,7 +429,8 @@ warn_skip_deps(AppInfo, State) -> false -> ok end; true -> - ?ERROR(Msg, Args), ?FAIL + ?ERROR(Msg, Args), + ?ABORT end. not_needs_compile(App) -> From 88113401f59e2cb0ea5348b9eab790fa2adf0ea4 Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Tue, 29 Sep 2020 13:13:14 +0000 Subject: [PATCH 3/7] friendlier debug mode in rebar_core --- src/rebar_core.erl | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/src/rebar_core.erl b/src/rebar_core.erl index 6a1cdbf0..d5114bfe 100644 --- a/src/rebar_core.erl +++ b/src/rebar_core.erl @@ -92,7 +92,8 @@ process_command(State, Command) -> Namespace = rebar_state:namespace(State), TargetProviders = providers:get_target_providers(Command, Providers, Namespace), CommandProvider = providers:get_provider(Command, Providers, Namespace), - ?DEBUG("Expanded command sequence to be run: ~p", [TargetProviders]), + ?DEBUG("Expanded command sequence to be run: ~w", + [[friendly_provider(P) || P <- TargetProviders]]), case CommandProvider of not_found when Command =/= do -> case Namespace of @@ -136,7 +137,7 @@ process_command(State, Command) -> do([], State) -> {ok, State}; do([ProviderName | Rest], State) -> - ?DEBUG("Provider: ~p", [ProviderName]), + ?DEBUG("Running provider: ~p", [friendly_provider(ProviderName)]), %% Special providers like 'as', 'do' or some hooks may be passed %% as a tuple {Namespace, Name}, otherwise not. Handle them %% on a per-need basis. @@ -176,3 +177,8 @@ format_error({bad_provider_namespace, {Namespace, Name}}) -> io_lib:format("Undefined command ~ts in namespace ~ts", [Name, Namespace]); format_error({bad_provider_namespace, Name}) -> io_lib:format("Undefined command ~ts", [Name]). + +%% @private help display a friendlier sequence of provider names by +%% omitting the default namespace if it's not there +friendly_provider({default, P}) -> P; +friendly_provider(P) -> P. From 8bb2f909cf532ed4d339d32764611d689a41ec0c Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Tue, 29 Sep 2020 13:28:11 +0000 Subject: [PATCH 4/7] move shell debug to diagnostic --- src/rebar_utils.erl | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/rebar_utils.erl b/src/rebar_utils.erl index 91082acb..70bbcd22 100644 --- a/src/rebar_utils.erl +++ b/src/rebar_utils.erl @@ -150,7 +150,7 @@ wordsize() -> sh_send(Command0, String, Options0) -> ?INFO("sh_send info:\n\tcwd: ~p\n\tcmd: ~ts < ~ts\n", [rebar_dir:get_cwd(), Command0, String]), - ?DEBUG("\topts: ~p\n", [Options0]), + ?DIAGNOSTIC("\topts: ~p\n", [Options0]), DefaultOptions = [use_stdout, abort_on_error], Options = [expand_sh_flag(V) @@ -177,8 +177,8 @@ sh_send(Command0, String, Options0) -> %% Val = string() | false %% sh(Command0, Options0) -> - ?DEBUG("sh info:\n\tcwd: ~p\n\tcmd: ~ts\n", [rebar_dir:get_cwd(), Command0]), - ?DEBUG("\topts: ~p\n", [Options0]), + ?DIAGNOSTIC("sh info:\n\tcwd: ~p\n\tcmd: ~ts\n", [rebar_dir:get_cwd(), Command0]), + ?DIAGNOSTIC("\topts: ~p\n", [Options0]), DefaultOptions = [{use_stdout, false}, debug_and_abort_on_error], Options = [expand_sh_flag(V) @@ -190,7 +190,7 @@ sh(Command0, Options0) -> Command = lists:flatten(patch_on_windows(Command0, proplists:get_value(env, Options0, []))), PortSettings = proplists:get_all_values(port_settings, Options) ++ [exit_status, {line, 16384}, use_stdio, stderr_to_stdout, hide, eof, binary], - ?DEBUG("Port Cmd: ~ts\nPort Opts: ~p\n", [Command, PortSettings]), + ?DIAGNOSTIC("Port Cmd: ~ts\nPort Opts: ~p\n", [Command, PortSettings]), Port = open_port({spawn, Command}, PortSettings), try From 0845425ce485a02b3a92e78b16f0119c3341aaca Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Tue, 29 Sep 2020 13:29:12 +0000 Subject: [PATCH 5/7] rename DEBUG to DIAGNOSTIC in crashdump messages --- src/rebar3.erl | 4 ++-- src/rebar_state.erl | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/rebar3.erl b/src/rebar3.erl index d830a303..1f9a041a 100644 --- a/src/rebar3.erl +++ b/src/rebar3.erl @@ -339,7 +339,7 @@ handle_error({error, {Module, Reason}}, Stacktrace) -> case code:which(Module) of non_existing -> ?CRASHDUMP("~p: ~p~n~p~n~n", [Module, Reason, Stacktrace]), - ?ERROR("Uncaught error in rebar_core. Run with DEBUG=1 to stacktrace or consult rebar3.crashdump", []), + ?ERROR("Uncaught error in rebar_core. Run with DIAGNOSTIC=1 to stacktrace or consult rebar3.crashdump", []), ?DEBUG("Uncaught error: ~p ~p", [Module, Reason]), ?INFO("When submitting a bug report, please include the output of `rebar3 report \"your command\"`", []); _ -> @@ -353,7 +353,7 @@ handle_error(Error, StackTrace) -> %% Nothing should percolate up from rebar_core; %% Dump this error to console ?CRASHDUMP("Error: ~p~n~p~n~n", [Error, StackTrace]), - ?ERROR("Uncaught error in rebar_core. Run with DEBUG=1 to see stacktrace or consult rebar3.crashdump", []), + ?ERROR("Uncaught error in rebar_core. Run with DIAGNOSTIC=1 to see stacktrace or consult rebar3.crashdump", []), ?DEBUG("Uncaught error: ~p", [Error]), case StackTrace of [] -> ok; diff --git a/src/rebar_state.erl b/src/rebar_state.erl index ba0ce0fe..4d2c2631 100644 --- a/src/rebar_state.erl +++ b/src/rebar_state.erl @@ -510,7 +510,7 @@ create_logic_providers(ProviderModules, State0) -> ?WITH_STACKTRACE(C,T,S) ?DEBUG("~p: ~p ~p", [C, T, S]), ?CRASHDUMP("~p: ~p~n~p~n~n~p", [C, T, S, State0]), - throw({error, "Failed creating providers. Run with DEBUG=1 for stacktrace or consult rebar3.crashdump."}) + throw({error, "Failed creating providers. Run with DIAGNOSTIC=1 for stacktrace or consult rebar3.crashdump."}) end. to_list(#state_t{} = State) -> From a2331633a7e16a9eb0e86c819cfdf45be3f2936f Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Tue, 29 Sep 2020 14:22:46 +0000 Subject: [PATCH 6/7] Reworking app discovery and dep fetching verbosity Move most stuff that have to do with effectiveness to the debug level, and some stuff that has to do with implementation details to diagnostics --- src/rebar_app_discover.erl | 6 ++++++ src/rebar_fetch.erl | 2 +- src/rebar_git_resource.erl | 8 ++++---- src/rebar_pkg_resource.erl | 6 +++--- src/rebar_prv_install_deps.erl | 2 +- 5 files changed, 15 insertions(+), 9 deletions(-) diff --git a/src/rebar_app_discover.erl b/src/rebar_app_discover.erl index de6566bb..1e08b77d 100644 --- a/src/rebar_app_discover.erl +++ b/src/rebar_app_discover.erl @@ -31,6 +31,12 @@ do(State, LibDirs) -> %% There may be a top level src which is an app and there may not %% Find it here if there is, otherwise define the deps parent as root TopLevelApp = define_root_app(Apps, State), + ?DEBUG("Found top-level apps: [~ts]~n\tusing config: ~p", + [case lists:flatten([[",",rebar_app_info:name(App)] || App <- Apps]) of + [] -> ""; + Str -> tl(Str) + end, + [{src_dirs, SrcDirs}, {lib_dirs, LibDirs}]]), %% Handle top level deps State1 = lists:foldl(fun(Profile, StateAcc) -> diff --git a/src/rebar_fetch.erl b/src/rebar_fetch.erl index b2acc6d8..3696b339 100644 --- a/src/rebar_fetch.erl +++ b/src/rebar_fetch.erl @@ -59,7 +59,7 @@ download_source_(AppInfo, State) -> code:del_path(filename:absname(filename:join(AppDir1, "ebin"))), FetchDir = rebar_app_info:fetch_dir(AppInfo), ok = rebar_file_utils:rm_rf(filename:absname(FetchDir)), - ?DEBUG("Moving checkout ~p to ~p", [TmpDir, filename:absname(FetchDir)]), + ?DIAGNOSTIC("Moving checkout ~p to ~p", [TmpDir, filename:absname(FetchDir)]), rebar_file_utils:mv(TmpDir, filename:absname(FetchDir)); Error -> Error diff --git a/src/rebar_git_resource.erl b/src/rebar_git_resource.erl index 6f0123ca..7a127444 100644 --- a/src/rebar_git_resource.erl +++ b/src/rebar_git_resource.erl @@ -369,12 +369,12 @@ parse_tags(Dir) -> git_clone_options() -> Option = case os:getenv("REBAR_GIT_CLONE_OPTIONS") of - false -> "" ; %% env var not set - Opt -> %% env var set to empty or others + false -> + "" ; + Opt -> + ?DEBUG("Git Clone Options: ~p",[Opt]), Opt end, - - ?DEBUG("Git clone Option = ~p",[Option]), Option. check_type_support() -> diff --git a/src/rebar_pkg_resource.erl b/src/rebar_pkg_resource.erl index c81df706..f50ac622 100644 --- a/src/rebar_pkg_resource.erl +++ b/src/rebar_pkg_resource.erl @@ -220,10 +220,10 @@ cached_download(TmpDir, CachePath, Pkg={pkg, Name, Vsn, _OldHash, _Hash, RepoCon CDN = maybe_default_cdn(State), case request(RepoConfig#{repo_url => CDN}, Name, Vsn, ETag) of {ok, cached} -> - ?INFO("Version cached at ~ts is up to date, reusing it", [CachePath]), + ?DEBUG("Version cached at ~ts is up to date, reusing it", [CachePath]), serve_from_cache(TmpDir, CachePath, Pkg); {ok, Body, NewETag} -> - ?INFO("Downloaded package, caching at ~ts", [CachePath]), + ?DEBUG("Downloaded package, caching at ~ts", [CachePath]), maybe_store_etag_in_cache(UpdateETag, ETagPath, NewETag), serve_from_download(TmpDir, CachePath, Pkg, Body); error when ETag =/= <<>> -> @@ -236,7 +236,7 @@ cached_download(TmpDir, CachePath, Pkg={pkg, Name, Vsn, _OldHash, _Hash, RepoCon maybe_default_cdn(State) -> CDN = rebar_state:get(State, rebar_packages_cdn, ?DEFAULT_CDN), - rebar_utils:to_binary(CDN). + rebar_utils:to_binary(CDN). -spec serve_from_cache(TmpDir, CachePath, Pkg) -> Res when TmpDir :: file:name(), diff --git a/src/rebar_prv_install_deps.erl b/src/rebar_prv_install_deps.erl index 52c57156..34334d51 100644 --- a/src/rebar_prv_install_deps.erl +++ b/src/rebar_prv_install_deps.erl @@ -382,7 +382,7 @@ symlink_dep(State, From, To) -> ok -> RelativeFrom = make_relative_to_root(State, From), RelativeTo = make_relative_to_root(State, To), - ?INFO("Linking ~ts to ~ts", [RelativeFrom, RelativeTo]), + ?DEBUG("Linking ~ts to ~ts", [RelativeFrom, RelativeTo]), ok; exists -> ok From 26064098fd34d028669b5cc3db00e718c34ddb03 Mon Sep 17 00:00:00 2001 From: Fred Hebert Date: Tue, 29 Sep 2020 16:32:07 +0000 Subject: [PATCH 7/7] Rework debug/diagnostic logs for compile tasks This should cover most cases, including hooks. What this specifically does is change some less useful messages for more contextualized ones, including tying specific configurations to actions taking place. This is particularly visible in hooks, and hopefully provides some amount of discoverability. Also of note: - ebin/ directory copying is called explicitly when done since people have issues with that - paths for compiled files are made relative since the analysis list shows the full paths already - hooks are a bit more verbose but also more useful. --- src/rebar_compiler.erl | 10 ++++----- src/rebar_compiler_epp.erl | 2 +- src/rebar_compiler_erl.erl | 4 ++-- src/rebar_hooks.erl | 42 ++++++++++++++++++++++++++------------ src/rebar_prv_compile.erl | 1 + 5 files changed, 38 insertions(+), 21 deletions(-) diff --git a/src/rebar_compiler.erl b/src/rebar_compiler.erl index e718eb41..d7081b00 100644 --- a/src/rebar_compiler.erl +++ b/src/rebar_compiler.erl @@ -321,21 +321,21 @@ compile_worker(Source, [Opts, Config, Outs, CompilerMod]) -> {Result, Source}. compile_handler({ok, Source}, _Args) -> - ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), Source]), + ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), filename:basename(Source)]), ok; compile_handler({{ok, Tracked}, Source}, [_, Tracking]) when Tracking -> - ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), Source]), + ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), filename:basename(Source)]), {ok, Tracked}; compile_handler({{ok, Warnings}, Source}, _Args) -> report(Warnings), - ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), Source]), + ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), filename:basename(Source)]), ok; compile_handler({{ok, Tracked, Warnings}, Source}, [_, Tracking]) when Tracking -> report(Warnings), - ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), Source]), + ?DEBUG("~sCompiled ~s", [rebar_utils:indent(1), filename:basename(Source)]), {ok, Tracked}; compile_handler({skipped, Source}, _Args) -> - ?DEBUG("~sSkipped ~s", [rebar_utils:indent(1), Source]), + ?DEBUG("~sSkipped ~s", [rebar_utils:indent(1), filename:basename(Source)]), ok; compile_handler({Error, Source}, [Config | _Rest]) -> NewSource = format_error_source(Source, Config), diff --git a/src/rebar_compiler_epp.erl b/src/rebar_compiler_epp.erl index 379fb1f1..cae28beb 100644 --- a/src/rebar_compiler_epp.erl +++ b/src/rebar_compiler_epp.erl @@ -145,7 +145,7 @@ list_directory(Dir, Cache) -> {Cache, []}, DirFiles), {NewFs#{Dir => Files}, Files}; {error, Reason} -> - ?DEBUG("Failed to list ~s, ~p", [Dir, Reason]), + ?DIAGNOSTIC("Failed to list ~s, ~p", [Dir, Reason]), {Cache, []} end end. diff --git a/src/rebar_compiler_erl.erl b/src/rebar_compiler_erl.erl index 88783ab0..587b3541 100644 --- a/src/rebar_compiler_erl.erl +++ b/src/rebar_compiler_erl.erl @@ -48,8 +48,8 @@ needed_files(Graph, FoundFiles, _, AppInfo) -> EbinDir = rebar_app_info:ebin_dir(AppInfo), RebarOpts = rebar_app_info:opts(AppInfo), ErlOpts = rebar_opts:erl_opts(RebarOpts), - ?DEBUG("erlopts ~p", [ErlOpts]), - ?DEBUG("files to compile ~p", [FoundFiles]), + ?DEBUG("compile options: {erl_opts, ~p}.", [ErlOpts]), + ?DEBUG("files to analyze ~p", [FoundFiles]), %% Make sure that the ebin dir is on the path ok = rebar_file_utils:ensure_dir(EbinDir), diff --git a/src/rebar_hooks.erl b/src/rebar_hooks.erl index 358458ed..481e6f6e 100644 --- a/src/rebar_hooks.erl +++ b/src/rebar_hooks.erl @@ -12,20 +12,34 @@ atom() | {atom(), atom()} | string(), [providers:t()], rebar_app_info:t(), rebar_state:t()) -> rebar_app_info:t(). run_all_hooks(Dir, Type, Command, Providers, AppInfo, State) -> + ?DEBUG("Running hooks for ~p in app ~ts (~ts) with configuration:", + [Command, rebar_app_info:name(AppInfo), Dir]), State1 = rebar_state:current_app(State, AppInfo), State2 = run_provider_hooks(Dir, Type, Command, Providers, rebar_app_info:opts(AppInfo), State1), run_hooks(Dir, Type, Command, rebar_app_info:opts(AppInfo), State1), rebar_state:current_app(State2). run_all_hooks(Dir, Type, Command, Providers, State) -> + ?DEBUG("Running hooks for ~p with configuration:", [Command]), run_provider_hooks(Dir, Type, Command, Providers, rebar_state:opts(State), State), run_hooks(Dir, Type, Command, rebar_state:opts(State), State). run_project_and_app_hooks(Dir, Type, Command, Providers, State) -> ProjectApps = rebar_state:project_apps(State), + ?DEBUG("Running app-specific hooks", []), [rebar_hooks:run_all_hooks(Dir, Type, Command, Providers, AppInfo, State) || AppInfo <- ProjectApps], + ?DEBUG("Running project-wide hooks", []), run_all_hooks(Dir, Type, Command, Providers, State). +format_error({bad_provider, Type, Command, {Name, Namespace}}) -> + io_lib:format("Unable to run ~ts hooks for '~p', command '~p' in namespace '~p' not found.", [Type, Command, Namespace, Name]); +format_error({bad_provider, Type, Command, Name}) -> + io_lib:format("Unable to run ~ts hooks for '~p', command '~p' not found.", [Type, Command, Name]). + +%%%%%%%%%%%%%%% +%%% PRIVATE %%% +%%%%%%%%%%%%%%% + run_provider_hooks(Dir, Type, Command, Providers, Opts, State) -> case rebar_opts:get(Opts, provider_hooks, []) of [] -> @@ -40,11 +54,14 @@ run_provider_hooks_(_Dir, _Type, _Command, _Providers, [], State) -> run_provider_hooks_(Dir, Type, Command, Providers, TypeHooks, State) -> case proplists:get_all_values(Command, TypeHooks) of [] -> + ?DEBUG("\t{provider_hooks, []}.", []), State; HookProviders -> rebar_paths:set_paths([plugins], State), Providers1 = rebar_state:providers(State), State1 = rebar_state:providers(rebar_state:dir(State, Dir), Providers++Providers1), + ?DEBUG("\t{provider_hooks, [{~p, ~p}]}.", + [Type, HookProviders]), case rebar_core:do(HookProviders, State1) of {error, ProviderName} -> ?DEBUG(format_error({bad_provider, Type, Command, ProviderName}), []), @@ -55,11 +72,6 @@ run_provider_hooks_(Dir, Type, Command, Providers, TypeHooks, State) -> end end. -format_error({bad_provider, Type, Command, {Name, Namespace}}) -> - io_lib:format("Unable to run ~ts hooks for '~p', command '~p' in namespace '~p' not found.", [Type, Command, Namespace, Name]); -format_error({bad_provider, Type, Command, Name}) -> - io_lib:format("Unable to run ~ts hooks for '~p', command '~p' not found.", [Type, Command, Name]). - run_hooks(Dir, pre, Command, Opts, State) -> run_hooks(Dir, pre_hooks, Command, Opts, State); run_hooks(Dir, post, Command, Opts, State) -> @@ -67,17 +79,21 @@ run_hooks(Dir, post, Command, Opts, State) -> run_hooks(Dir, Type, Command, Opts, State) -> case rebar_opts:get(Opts, Type, []) of [] -> - ?DEBUG("run_hooks(~p, ~p, ~p) -> no hooks defined\n", [Dir, Type, Command]), + ?DEBUG("\t{~p, []}.", [Type]), + ?DIAGNOSTIC("run_hooks(~p, ~p, ~p) -> no hooks defined\n", [Dir, Type, Command]), ok; Hooks -> Env = rebar_env:create_env(State, Opts), - lists:foreach(fun({_, C, _}=Hook) when C =:= Command -> - apply_hook(Dir, Env, Hook); - ({C, _}=Hook) when C =:= Command -> - apply_hook(Dir, Env, Hook); - (_) -> - continue - end, Hooks) + CommandHooks = lists:filter( + fun({_, C, _}) when C =:= Command -> true; + ({C, _}) when C =:= Command -> true; + (_) -> false + end, + Hooks + ), + ?DEBUG("\t{~p, ~p}.", + [Type, CommandHooks]), + lists:foreach(fun(Hook) -> apply_hook(Dir, Env, Hook) end, CommandHooks) end. apply_hook(Dir, Env, {Arch, Command, Hook}) -> diff --git a/src/rebar_prv_compile.erl b/src/rebar_prv_compile.erl index 252c3620..f799cbd0 100644 --- a/src/rebar_prv_compile.erl +++ b/src/rebar_prv_compile.erl @@ -378,6 +378,7 @@ copy_app_dirs(AppInfo, OldAppDir, AppDir) -> true -> OutEbin = filename:join([AppDir, "ebin"]), filelib:ensure_dir(filename:join([OutEbin, "dummy.beam"])), + ?DEBUG("Copying existing files from ~ts to ~ts", [EbinDir, OutEbin]), rebar_file_utils:cp_r(filelib:wildcard(filename:join([EbinDir, "*"])), OutEbin); false -> ok