Only append highlight to Exception#to_s, not #message

[casperisfine]

I made a PR to showcase the idea, but I suppose there's many alternatives to this PR.

The issue I ran into when testing our app against ruby-head, is that we definitely disable error_highlight in production, however on CI it can be useful. But then it breaks lots of assertions about logs and error messages in our test suite.

Since ultimately the main goal of error_highlight is to show that extended message in things like IRB, etc, I'm thinking it could override #to_s, but leave #message untouched.

cc @mame what do you think?

[mame]

I'm sorry but I cannot get your point.

we definitely disable error_highlight in production

Sorry to hear that. Could you explain the reason?

One of the original motivations of this gem is to reduce confusion having to guess what part of the expression is wrong when reading an error log in an application monitoring service like Sentry. See https://bugs.ruby-lang.org/issues/17930#note-1 . So, I suppose this gem to be useful in production rather than on CI.

But then it breaks lots of assertions about logs and error messages in our test suite.

I understand this problem. IMO, it is not a good practice for a test to exactly check an error message, but I know that there are actually lots of tests that do that. How about disabling error_highlight on CI for a while, and fixing such tests gradually?

I'm thinking it could override #to_s, but leave #message untouched.

I'm unsure about your idea. A highlighted snippet should be printed to stderr when the ruby interpreter fails, as follows:

$ ruby -e '1.time {}'
-e:1:in `<main>': undefined method `time' for 1:Integer (NoMethodError)

1.time {}
 ^^^^^
Did you mean?  times

The interpreter uses Exception#message to print the error log, so this is not achieved by just overriding #to_s. Do you mean changing the ruby interpreter too?

BTW, this approach of this gem (extending Exception#message) is copied from did_you_mean gem. Thus, changing the error printing mechanism may affect did_you_mean. Also, the test that fails due to error_highlight will also potentially fail if you define a new method that triggers did_you_mean suggestion.

[casperisfine]

I'm sorry but I cannot get your point.

Probably my bad, I'll try to be clearer.

Sorry to hear that. Could you explain the reason?

No need to be sorry. Same reason we already disable did_you_mean in production. We'd rather avoid any overhead in production environments. Maybe error_highlight 's overhead is much smaller than did_you_mean?

IMO, it is not a good practice for a test to exactly check an error message

Agreed, and I already started rewriting these tests to use assert_match instead.

There's just one case where it's a bit tricky, e.g.:

Rails.logger.error("blah blah error=#{exception.message} some_id=#{some_id}")

In this case the error message becoming multiline is a bit problematic for us.

The interpreter uses Exception#message to print the error log, so this is not achieved by just overriding #to_s. Do you mean changing the ruby interpreter too?

Ah I didn't know that. Maybe Exception could be slightly changed to better allow did_you_mean and error_highlight to integrate themselves?

did_you_mean defines original_message, and in some places we do have to be careful to avoid calling message, e.g.: https://github.com/rails/rails/blob/f95c0b7e96eb36bc3efc0c5beffbb9e84ea664e4/activesupport/lib/active_support/core_ext/name_error.rb#L13-L16

Maybe Ruby could define both message and full_message (or something like that). So that we can get either the "base" error message, or the full message with extra developer infos?

How does that sound? Also is my case a bit clearer now?

[mame]

Sorry to hear that. Could you explain the reason?

No need to be sorry. Same reason we already disable did_you_mean in production. We'd rather avoid any overhead in production environments.

Ah performance. They indeed bring some overhead.

Maybe error_highlight 's overhead is much smaller than did_you_mean?

Just for the record: According to the following micro benchmark, the ruby interpreter seems to take about < 0.1 sec., error_highlight does 0.5 sec., and did_you_mean does 3.4 sec. (But the performance of error_highlight depends on the length of the whole source code.)

10000.times do
  begin
    1.time {}
  rescue NoMethodError
    $!.message
  end
end

$ time ruby --disable-did_you_mean --disable-error_highlight test.rb # 0.070s (= only the interpreter core)
$ time ruby --disable-did_you_mean                           test.rb # 0.546s (= core + error_highlight)
$ time ruby                        --disable-error_highlight test.rb # 3.418s (= core + did_you_mean)

Anyway, I agree that disabling them may be reasonable for a very high-intensity service.

Agreed, and I already started rewriting these tests to use assert_match instead.

Yeah, thanks!

In this case the error message becoming multiline is a bit problematic for us.

As you may know, there is such a message in the core, regardless of did_you_mean and error_highlight.

$ ruby -e 'Marshal.load("foo")'
-e:1:in `load': incompatible marshal file format (can't be read) (TypeError)
        format version 4.8 required; 102.111 given
        from -e:1:in `<main>'

It is unfortunately a wrong assumption that Exception#message is one-line. I admit that a multi-line error message is not very common, though.

Maybe Ruby could define both message and full_message (or something like that). So that we can get either the "base" error message, or the full message with extra developer infos?

It makes sense to me. If the ruby interpreter provides a better extension API to add an auxiliary information into an error log, I will be happy to integrate error_highlight by using it.

If we assume that the first line of any error message is self-contained, a simpler alternative idea is to provide Exception#oneline_message or something like this:

class Exception
  def oneline_message
    message.lines.first
    # or more effectively, message[/^.*$/]
  end
end

FYI: There is already Exception#full_message which returns a string that contains not only Exception#message but also a backtrace.

https://docs.ruby-lang.org/en/3.0.0/Exception.html#method-i-full_message

How does that sound? Also is my case a bit clearer now?

Yes, thank you for the explanation!

[casperisfine]

Just for the record: According to the following micro benchmark

Yeah, but as you point, it's heavily dependent on the data being scanned. I've seen did_you_mean take several seconds in extreme cases (because the sheer amount of constants and methods we have), we can't afford this in production.

error_highlight might be cheaper, but I worry about the memory overhead. Anyway...

If the ruby interpreter provides a better extension API to add an auxiliary information into an error log, I will be happy to integrate error_highlight by using it.

Ok, so I suppose I should open a ticket upstream. I'm just really unsure what such API look like.

[svoop]

Here's another use case to upvote oneline_message or alike:

When writing CLI executables, I usually rescue from all exceptions and print only one line with (until now) the error.message. This is sufficient for users of the CLI who are not familiar with Ruby. To get the full rap, you'd run the CLI executable with an argument such as "-v/--verbose".

Unfortunately, with the otherwise very useful error_highlight gem, a failing run now looks like so:

(As a side note: This is not a typical error message, it's just the easiest way to pull an example since I'm revamping this tool. A more typical one would be "runway 16L undeclared for airfield LFNT".)

Adding --disable-error_highlight to the shebang of the executable is no solution, since it introduces coupling to the Ruby version and always suppresses the highlight, even when it is desired as part of verbose output.

Update: As a workaround, error.message.lines.first.chomp does the job. However, a more explicit API could help to raise awareness of multi-line error messages.

[mame]

@svoop I am afraid if I understand your problem correctly. Could you elaborate your situation?

Do you want for your program to print:

Error: undefined method `surface=' for #<AIXM::Feature::Airport id="LFC551D33B">

in the situation you said? I don't think the message is friendly for an end user, with or without the suggestion of error_highlight.

My practice is to show an unexpected exception as "internal error" or something, like this.

begin
  main_code
rescue MyAppError
  puts "Error: #{ $!.message }"
rescue Exception
  puts "Internal Error: #{ $!.message }"
end

If it is printed as "Internal Error", error_highlight suggestion does not matter much, IMO.

(As a side note: This is not a typical error message, it's just the easiest way to pull an example since I'm revamping this tool. A more typical one would be "runway 16L undeclared for airfield LFNT".)

Currently, error_highlight modifies only NameError's message. So if you are raising the message with your own exception class rather than NameError, error_highlight should not modify your error message. If it does, it is a bug. I would be happy if you could provide reproducible code.

I want to extend error_highlight suggestions to other exception classes than NameError, but I know it is dangerous. So I'm now proposing a dedicated API for error_highlight and did_you_mean to add suggestions https://bugs.ruby-lang.org/issues/18438

[svoop]

@mame

Do you want for your program to print:

Error: undefined method `surface=' for #<AIXM::Feature::Airport id="LFC551D33B">

Exactly, something like the oneline_message you suggested to have a well-defined API for such use cases (logging, special purpose etc).

in the situation you said? I don't think the message is friendly for an end user, with or without the suggestion of error_highlight.

Oh, believe me, it is. 😄 This is a parser (CLI tool) which every 28 days (when new aeronautical documentation sets are published) may have to be adapted to structural changes upstream. So the end user for these error messages is a developer and it is meaningful enough to decide whether you have to act immediately and tackle the problem, since these publications concern air traffic safety and are time-sensitive.

The parser features postmortem drilldown to the conflicting code using debugger for the actual work, the error message in "non-verbose" mode (screenshot above) is merely a wakeup call.

[mame]

Thank you for your reply!

So the end user for these error messages is a developer

Okay I see. But then, I'm not sure why a few lines of error_highlight would be a big deal.

Anyway, I think https://bugs.ruby-lang.org/issues/18438 will solve the issue. But we need to wait for Ruby 3.2 at the earliest. For Ruby 3.1, you may want to use NameError#original_message that error_highlight (and did_you_mean) provides.

begin
  1.time
rescue Exception
  p $!.message          #=> "undefined method `time' for 1:Integer\n\n  1.time\n   ^^^^^\nDid you mean?  times"
  p $!.original_message #=> "undefined method `time' for 1:Integer"
end

Note that other exception classes don't provide #original_message, so you need to check if it responds, like this:

msg = $!.respond_to?(:original_message) ? $!.original_message : $!.message
puts "Error: #{ msg }"

[svoop]

@mame Cool, original_message totally cuts it for me! Thanks for the hint and sorry for the OT noise.

[mame]

Ruby 3.2 will introduce a new API, Exception#detailed_message to extend the error message without changing #message.

https://bugs.ruby-lang.org/issues/18564

Now error_highlight uses the new API if available. I think that solves the problem, so I close this. Thank you!

[casperisfine]

Thank you! 🙇