Better support for error_highlight (and similar)

[voxik]

I have just looked into why asciidoctor-pdf is broken in Fedora and this is the error:

  1) Asciidoctor::PDF::Converter#convert theme should log error with filename and reason if exception is thrown during theme compilation
     Failure/Error: (expect logger).to have_message expected
       expected ERROR message matching `(?-mix:because of NoMethodError undefined method `start_with\?' for 10:(Fixnum|Integer); reverting to default theme)' to have been logged, but got ERROR: could not locate or load the built-in pdf theme `/builddir/build/BUILD/asciidoctor-pdf-1.6.1/spec/fixtures/invalid-theme.yml' because of NoMethodError undefined method `start_with?' for 10:Integer
                     if (path.start_with? 'GEM_FONTS_DIR') && (sep = path[13])
                             ^^^^^^^^^^^^; reverting to default theme
     # ./spec/spec_helper.rb:644:in `block (3 levels) in <top (required)>'
     # ./spec/spec_helper.rb:508:in `with_memory_logger'
     # ./spec/spec_helper.rb:640:in `block (2 levels) in <top (required)>'
     # ./spec/converter_spec.rb:162:in `block (4 levels) in <top (required)>'

This is apparently caused by error_highlight gem introduced in Ruby 3.1 and it seems it has been fixed by 0fc983c86cdf49f0ce46618aab67e765e32ee0db. But replacing part of the error message seems to be big hammer, especially since Ruby is going to introduce yet another helper gem (syntax_suggest) in Ruby 3.2.

Other project had to deal with this and notably this is how it was fixed in RSpec:

https://github.com/rspec/rspec-expectations/pull/1339/files

So it seems that the DidYouMean gem (which was first in line of these developer friendly tools) keeps the plain Ruby error and it can be accessed via original_message if available. I think that this would also be better approach for asciidoctor-pdf.

[mojavelinux]

I'm confused. Are you saying it has been fixed, or that the fix didn't work? We need to modify the error message to make it make sense. I first want to establish whether there is actually a bug, because all the tests are passing in CI.

[mojavelinux]

Please note that Asciidoctor PDF < 2.0.0 is no longer supported and will not be receiving any more updates.

[mojavelinux]

I'm confident that this error has already been fixed and the risk mitigated. We have no plans to release another version in the 1.6.x line since that release line has been closed for development. Therefore, I'm closing this issue as already resolved. Please use at least Asciidoctor PDF 2, preferably 2.3.

[voxik]

I am saying that the https://github.com/asciidoctor/asciidoctor-pdf/commit/0fc983c86cdf49f0ce46618aab67e765e32ee0db is more workaround then proper fix. It cuts off some part of the message without too much knowledge what is inside. Let me explain.

In Ruby 3.0 and older, the error message which is checked in the test case looked like:

ERROR: could not locate or load the built-in pdf theme `/builddir/build/BUILD/asciidoctor-pdf-1.6.1/spec/fixtures/invalid-theme.yml' because of NoMethodError undefined method `start_with?' for 10:Integer

That was it. But if error_highlight is enabled in Ruby 3.1+, it contains additional debug information:

ERROR: could not locate or load the built-in pdf theme `/builddir/build/BUILD/asciidoctor-pdf-1.6.1/spec/fixtures/invalid-theme.yml' because of NoMethodError undefined method `start_with?' for 10:Integer
                     if (path.start_with? 'GEM_FONTS_DIR') && (sep = path[13])
                             ^^^^^^^^^^^^

The current solution is:

diff --git a/lib/asciidoctor/pdf/converter.rb b/lib/asciidoctor/pdf/converter.rb
index bf10dcc7e..b5720978e 100644
--- a/lib/asciidoctor/pdf/converter.rb
+++ b/lib/asciidoctor/pdf/converter.rb
@@ -444,7 +444,7 @@ def load_theme doc
             message = %(could not locate or load the built-in pdf theme `#{theme_name}')
           end
           message += %( because of #{$!.class} #{$!.message})
-          log :error, %(#{message}; reverting to default theme)
+          log :error, (message.sub %r/$/, '; reverting to default theme')
           @themesdir = (theme = ThemeLoader.load_theme).__dir__
           prepare_theme theme
         end

I.e. cut everything behind end of line and replace it with 'reverting to default theme'. If the intention is to fiddle around with the message, the better solution would be:

diff --git a/lib/asciidoctor/pdf/converter.rb b/lib/asciidoctor/pdf/converter.rb
index ac4dd13b..ec035028 100644
--- a/lib/asciidoctor/pdf/converter.rb
+++ b/lib/asciidoctor/pdf/converter.rb
@@ -549,8 +549,8 @@ def load_theme doc
           else
             message = %(could not locate or load the built-in pdf theme `#{theme_name}')
           end
-          message += %( because of #{$!.class} #{$!.message})
-          log :error, (message.sub %r/$/, '; reverting to default theme')
+          message += %( because of #{$!.class} #{$!.respond_to?(:original_message) ? $!.original_message : $!.message})
+          log :error, %(#{message}; reverting to default theme)
           @themesdir = (theme = ThemeLoader.load_theme).__dir__
           prepare_theme theme
         end

However, the question is what is the real intent here. If it is provide the original message with some extended asciidoctor-pdf, then the test case should be adjusted instead.

P.S. the version is just red herring. That is what I have at hand. And if I used some more recent version, I would probably not notice that there could be IMHO better way, because it would just work.

[mojavelinux]

Your understanding of what the code is doing is not correct. All the code is doing is inserting additional context at the location of the first newline. It is not cutting away any part of the message.

I'm not going to put in hacks that use the undocumented original_message property. Besides, there is no need as the tests prove that the code is working exactly as expected.

[voxik]

Your understanding of what the code is doing is not correct. All the code is doing is inserting additional context at the location of the first newline. It is not cutting away any part of the message.

I'm not going to put in hacks that use the undocumented original_message property. Besides, there is no need as the tests prove that the code is working exactly as expected.

Well, you already put hack there, you replace end of $!.message with '; reverting to default theme'. This is not less documented then the original_message.

But if you don't put hacks inside, then the test case should be fixed to accept that Ruby 3.1+ provides additional debug information in the exception.

[mojavelinux]

you already put hack there, you replace end of $!.message with '; reverting to default theme'

That's not a hack. The code is writing to a documented property of the error object.

test case should be fixed to accept that Ruby 3.1+ provides additional debug information in the exception.

The tests already do run on Ruby 3.1, so I'm not sure why you are suggesting that the test needs to be changed to work.

[voxik]

IOW with Ruby 3.1 and error_highlihgt, this test is wrong:

https://github.com/asciidoctor/asciidoctor-pdf/blob/06040c03682c3e3365a3f09af850f4acafada7e0/spec/converter_spec.rb#L330

You have already put one workaround at place. If you don't want any, the the test should be fixed and possible the error handling as well, so it is readable.

[mojavelinux]

Are you saying that in order to get the test to fail, I need to load the error_highlight gem?

[voxik]

Ok, I was wrongly reading the code, sorry about that. What it does is changing the error from:

could not locate or load the built-in pdf theme `/builddir/build/BUILD/asciidoctor-pdf-1.6.1/spec/fixtures/invalid-theme.yml' because of NoMethodError undefined method `start_with?' for 10:Integer
                     if (path.start_with? 'GEM_FONTS_DIR') && (sep = path[13])
                             ^^^^^^^^^^^^; reverting to default theme

to

could not locate or load the built-in pdf theme `/builddir/build/BUILD/asciidoctor-pdf-1.6.1/spec/fixtures/invalid-theme.yml' because of NoMethodError undefined method `start_with?' for 10:Integer; reverting to default theme
                     if (path.start_with? 'GEM_FONTS_DIR') && (sep = path[13])
                             ^^^^^^^^^^^^

IOW moving the ; reverting to default theme around.

Nevertheless, your assertion about The code is writing to a documented property of the error object. is not completely true IMHO. The problem is that the error message is not specified at all. The code and test did some assumptions, the situation changed and with that also the assumptions. The original_message as I proposed originally would not be any better. From this POV the fix is valid.

Thank you for helping me understand the code and sorry for the noise.

[mojavelinux]

IOW moving the ; reverting to default theme around.

Exactly. Otherwise, it gets mixed up with the formatted error message. The first line is the "safe" area to add additional notations.

Nevertheless, your assertion about The code is writing to a documented property of the error object. is not completely true IMHO.

I meant to say that it is reading from the documented property of the error object, which is $!.message. That's the only error message we are given. And we are preserving it.

The code and test did some assumptions, the situation changed and with that also the assumptions.

I still don't understand what assumption you are talking about. The tests verify exactly what the user sees, which is this:

asciidoctor: ERROR: could not locate or load the built-in pdf theme `./my-theme.yml' because of NoMethodError undefined method `start_with?' for 10:Integer; reverting to default theme

              if (path.start_with? 'GEM_FONTS_DIR') && (sep = path[13])
                      ^^^^^^^^^^^^

We are putting everything we can put in a log message that is provided in this context. There is no other information available.