Skip to content

Commit

Permalink
🎨 Exception logging improvements
Browse files Browse the repository at this point in the history
- Formatted shell error logging statements to be more readily recognized in IDE terminal windows
- Shortened shell failure exception messages
- Consolidated, simplified, and fixed formatting of debug exception backtraces
  • Loading branch information
mkarlesky committed Oct 29, 2024
1 parent 33c05c5 commit f08576b
Show file tree
Hide file tree
Showing 10 changed files with 53 additions and 39 deletions.
9 changes: 4 additions & 5 deletions bin/ceedling
Original file line number Diff line number Diff line change
Expand Up @@ -32,14 +32,13 @@ def boom_handler(loginator, exception)

if !loginator.nil?
loginator.log( exception.message, Verbosity::ERRORS, LogLabels::EXCEPTION )
loginator.log( "Backtrace ==>", Verbosity::DEBUG )
# Output to console the exception backtrace, formatted like Ruby does it
loginator.log( "#{exception.backtrace.first}: #{exception.message} (#{exception.class})", Verbosity::DEBUG )
loginator.log( exception.backtrace.drop(1).map{|s| "\t#{s}"}.join("\n"), Verbosity::DEBUG )

# Debug backtrace (only if debug verbosity)
loginator.log_debug_backtrace( exception )

# Something went really wrong... logging isn't even up and running yet
else
$stderr.puts( "#{exception.class} ==> #{exception.message}" )
$stderr.puts( exception.message )
$stderr.puts( "Backtrace ==>" )
$stderr.puts( exception.backtrace )
end
Expand Down
25 changes: 16 additions & 9 deletions lib/ceedling/exceptions.rb
Original file line number Diff line number Diff line change
Expand Up @@ -13,28 +13,35 @@ class CeedlingException < RuntimeError
end


class ShellExecutionException < CeedlingException
class ShellException < CeedlingException

attr_reader :shell_result

def initialize(shell_result:{}, name:, message:'')
@shell_result = shell_result

_message = ''

# If shell results exist...
# Most shell exceptions will be from build compilation and linking.
# The formatting of these messages should place the tool output on its own
# lines without any other surrounding characters.
# This formatting maximizes the ability of IDEs to parse, highlight, and make
# actionable the build errors that appear within their terminal windows.

# If shell results exist, report the exit code...
if !shell_result.empty?
message = "Tool #{name} terminated with exit code [#{shell_result[:exit_code]}]"
_message = "#{name} terminated with exit code [#{shell_result[:exit_code]}]"

if !shell_result[:output].empty?
message += " and output >> \"#{shell_result[:output].strip()}\""
_message += " and output >>\n#{shell_result[:output].strip()}"
end

super( message )

# Otherwise, just report the provided message
# Otherwise, just report the exception message
else
message = "Tool #{name} encountered an error:: #{message}"
super( message )
_message = "#{name} encountered an error with output >>\n#{message}"
end

# Hand the message off to parent Exception
super( _message )
end
end
6 changes: 3 additions & 3 deletions lib/ceedling/generator.rb
Original file line number Diff line number Diff line change
Expand Up @@ -167,7 +167,7 @@ def generate_object_file_c(

begin
shell_result = @tool_executor.exec( command )
rescue ShellExecutionException => ex
rescue ShellException => ex
shell_result = ex.shell_result
raise ex
ensure
Expand Down Expand Up @@ -230,7 +230,7 @@ def generate_object_file_asm(

begin
shell_result = @tool_executor.exec( command )
rescue ShellExecutionException => ex
rescue ShellException => ex
shell_result = ex.shell_result
raise ex
ensure
Expand Down Expand Up @@ -270,7 +270,7 @@ def generate_executable_file(tool, context, objects, flags, executable, map='',

begin
shell_result = @tool_executor.exec( command )
rescue ShellExecutionException => ex
rescue ShellException => ex
shell_result = ex.shell_result
raise ex
ensure
Expand Down
10 changes: 10 additions & 0 deletions lib/ceedling/loginator.rb
Original file line number Diff line number Diff line change
Expand Up @@ -161,6 +161,16 @@ def log(message="\n", verbosity=Verbosity::NORMAL, label=LogLabels::AUTO, stream
end


def log_debug_backtrace(exception)
log( "\nDebug Backtrace ==>", Verbosity::DEBUG )

# Send backtrace to debug logging, formatted almost identically to how Ruby does it.
# Don't log the exception message itself in the first `log()` call as it will already be logged elsewhere
log( "#{exception.backtrace.first}: (#{exception.class})", Verbosity::DEBUG )
log( exception.backtrace.drop(1).map{|s| "\t#{s}"}.join("\n"), Verbosity::DEBUG )
end


def decorate(str, label=LogLabels::NONE)
return str if !@decorators

Expand Down
16 changes: 8 additions & 8 deletions lib/ceedling/tasks_release.rake
Original file line number Diff line number Diff line change
Expand Up @@ -11,8 +11,11 @@ require 'ceedling/file_path_utils'

desc "Build release target."
task RELEASE_SYM => [:prepare] do
header = "Release build '#{File.basename(PROJECT_RELEASE_BUILD_TARGET)}'"
@ceedling[:loginator].log("\n\n#{header}\n#{'-' * header.length}")
header = "Release build '#{File.basename( PROJECT_RELEASE_BUILD_TARGET )}'"

banner = @ceedling[:reportinator].generate_banner( header )

@ceedling[:loginator].log( banner )

begin
@ceedling[:plugin_manager].pre_release
Expand All @@ -30,13 +33,10 @@ task RELEASE_SYM => [:prepare] do
rescue StandardError => ex
@ceedling[:application].register_build_failure

@ceedling[:loginator].log( "#{ex.class} ==> #{ex.message}", Verbosity::ERRORS, LogLabels::EXCEPTION )
@ceedling[:loginator].log( ex.message, Verbosity::ERRORS, LogLabels::EXCEPTION )

# Debug backtrace
@ceedling[:loginator].log( "Backtrace ==>", Verbosity::DEBUG )
# Output to console the exception backtrace, formatted like Ruby does it
@ceedling[:loginator].log( "#{ex.backtrace.first}: #{ex.message} (#{ex.class})", Verbosity::DEBUG )
@ceedling[:loginator].log( ex.backtrace.drop(1).map{|s| "\t#{s}"}.join("\n"), Verbosity::DEBUG )
# Debug backtrace (only if debug verbosity)
@ceedling[:loginator].log_debug_backtrace( ex )
ensure
@ceedling[:plugin_manager].post_release
end
Expand Down
14 changes: 6 additions & 8 deletions lib/ceedling/test_invoker.rb
Original file line number Diff line number Diff line change
Expand Up @@ -407,16 +407,14 @@ def setup_and_invoke(tests:, context:TEST_SYM, options:{})

# Handle application-level exceptions.
# StandardError is the parent class of all application-level exceptions.
# Runtime errors (parent is Exception) continue on up to be caught by Ruby itself.
rescue StandardError => e
# Runtime errors (parent is Exception) continue on up to be handled by Ruby itself.
rescue StandardError => ex
@application.register_build_failure
@loginator.log( "#{e.class} ==> #{e.message}", Verbosity::ERRORS, LogLabels::EXCEPTION )

# Debug backtrace
@loginator.log("Backtrace ==>", Verbosity::DEBUG)
if @verbosinator.should_output?(Verbosity::DEBUG)
@loginator.log(e.backtrace, Verbosity::DEBUG)
end
@loginator.log( ex.message, Verbosity::ERRORS, LogLabels::EXCEPTION )

# Debug backtrace (only if debug verbosity)
@loginator.log_debug_backtrace( ex )
end
end

Expand Down
2 changes: 1 addition & 1 deletion lib/ceedling/test_invoker_helper.rb
Original file line number Diff line number Diff line change
Expand Up @@ -298,7 +298,7 @@ def generate_executable_now(context:, build_path:, executable:, objects:, flags:
@file_path_utils.form_test_build_map_filepath( build_path, executable ),
lib_args,
lib_paths )
rescue ShellExecutionException => ex
rescue ShellException => ex
if ex.shell_result[:output] =~ /symbol/i
notice = "If the linker reports missing symbols, the following may be to blame:\n" +
" 1. This test lacks #include statements corresponding to needed source files (see note below).\n" +
Expand Down
6 changes: 3 additions & 3 deletions lib/ceedling/tool_executor.rb
Original file line number Diff line number Diff line change
Expand Up @@ -70,9 +70,9 @@ def exec(command, args=[])
end
shell_result[:time] = time

# Ultimately, re-raise the exception as ShellExecutionException populated with the exception message
# Ultimately, re-raise the exception as ShellException populated with the exception message
rescue => error
raise ShellExecutionException.new( name:pretty_tool_name( command ), message: error.message )
raise ShellException.new( name:pretty_tool_name( command ), message: error.message )

# Be sure to log what we can
ensure
Expand All @@ -88,7 +88,7 @@ def exec(command, args=[])
# Go boom if exit code is not 0 and that code means a fatal error
# (Sometimes we don't want a non-0 exit code to cause an exception as the exit code may not mean a build-ending failure)
if ((shell_result[:exit_code] != 0) and options[:boom])
raise ShellExecutionException.new( shell_result:shell_result, name:pretty_tool_name( command ) )
raise ShellException.new( shell_result:shell_result, name:pretty_tool_name( command ) )
end

return shell_result
Expand Down
2 changes: 1 addition & 1 deletion plugins/gcov/lib/gcovr_reportinator.rb
Original file line number Diff line number Diff line change
Expand Up @@ -312,7 +312,7 @@ def run(opts, args, boom)

begin
shell_result = @tool_executor.exec( command )
rescue ShellExecutionException => ex
rescue ShellException => ex
result = ex.shell_result
@reportinator_helper.print_shell_result( result )
raise(ex) if gcovr_exec_exception?( opts, result[:exit_code], boom )
Expand Down
2 changes: 1 addition & 1 deletion plugins/gcov/lib/reportgenerator_reportinator.rb
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,7 @@ def generate_reports(opts)
# Generate the report(s).
begin
shell_result = run(args)
rescue ShellExecutionException => ex
rescue ShellException => ex
shell_result = ex.shell_result
# Re-raise
raise ex
Expand Down

0 comments on commit f08576b

Please sign in to comment.