Mastodon: NoMethodError in LinkCrawlWorker

[tateisu]

on v3.1.1

NoMethodError: undefined method `message' for "Net::ReadTimeout with #<TCPSocket:(closed)>":String

LinkCrawlWorker 
NoMethodError: undefined method `message' for "execution expired":String

LinkCrawlWorker 
NoMethodError: undefined method `message' for "end of file reached":String

LinkCrawlWorker 
NoMethodError: undefined method `message' for "Net::OpenTimeout":String

[Gargron]

I’ve noticed at least one of those in my own logs. Something isn’t right, exceptions aren’t strings but here clearly some of them have been converted to strings!

The thing is, it’s impossible to raise an error that doesn’t inherit from the StandardError class, so how does this happen? The C explanation doesn’t work because Net::ReadTimeout would not appear in C code

[tateisu]

I think these are came from uploading preview card thumbnails to object storage.

[ThibG]

Going by other reports, the exception is probably raised by the following rescue block somehow catching an object that is actually a string:
https://github.com/tootsuite/mastodon/blob/24cd2126c6cfb80844ef9ffbf61647b3d9afdc68/app/lib/request.rb#L77

Since I've been completely unable to reproduce it, it is likely this is not coming from the http gem, but from the block passed to perform and executed in:
https://github.com/tootsuite/mastodon/blob/24cd2126c6cfb80844ef9ffbf61647b3d9afdc68/app/lib/request.rb#L75

Something common to all reports I have seen is that those used external object storage, so I would blame the gem providing support for that…

Furthermore, as it seems to be indeed impossible to raise such an exception from ruby itself, this is probably a C extension doing that… since the exceptions are different, I suspect this is an issue with handling exceptions from Ruby functions the C extension would itself call (mostly through blocks), but I haven't found anything fishy so far…

[hugogameiro]

I am also getting LinkCrawlWorker jobs hanging (just freeze, without error message) on Sidekiq when processing some preview_card images but I can only randomly reproduce it with Docker. Problem present in testing both using local file system and remote object storage.

[nightpool]

this sounds like a bug we should approach the ruby core team about....

On Fri, Feb 14, 2020, 6:30 PM Hugo Gameiro [e-mail] wrote:

I am also getting LinkCrawlWorker jobs hanging (just freeze, without error
message) on Sidekiq when processing some preview_card images but I can only
randomly reproduce it with Docker. Problem present in testing both using
local file system and remote object storage.

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
https://github.com/tootsuite/mastodon/issues/13086?email_source=notifications&email_token=AABZCV426ARNMK4TWSUJF5LRC4SSDA5CNFSM4KUMPIL2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEL2ZBDQ#issuecomment-586518670,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AABZCV5QKGTMSD3B5U2HQHDRC4SSDANCNFSM4KUMPILQ
.

[ThibG]

In order to try getting some context for where the bogus exceptions are raised, could you try applying the following patch and monitor logs for “Caught exception was a String”?

diff --git a/app/lib/request.rb b/app/lib/request.rb
index c476e7785..20edc192f 100644
--- a/app/lib/request.rb
+++ b/app/lib/request.rb
@@ -74,7 +74,12 @@ class Request

       yield response if block_given?
     rescue => e
-      raise e.class, e.message, e.backtrace[0]
+      if e.respond_to?(:message)
+        raise e.class, e.message, e.backtrace[0]
+      else
+        Rails.logger.error "Caught exception was a String: #{caller_locations.inspect}"
+        raise e
+      end
     ensure
       http_client.close unless http_client.persistent?
     end

[hugogameiro]

On my end making those changes to request.rb will not log any errors for the LinkCrawlWorker jobs stuck in Sidekiq but I am not entirely sure that my issue is the same as OP as I never got the exceptions. But it's a big coincidence that I am also having LinkCrawlWorker issues since v3.1.1

[hugogameiro]

Just to confirm that my issue is not the same as OP, so my testing of the patched request.rb can be ignored. Solved my problem as explained https://github.com/tootsuite/mastodon/issues/9362#issuecomment-586936878

[ThibG]

Thinking about it, the earlier patch probably wouldn't have given more info. We could, however, try accessing the last raised backtrace ($@), if it exists:

diff --git a/app/lib/request.rb b/app/lib/request.rb
index c476e7785..20edc192f 100644
--- a/app/lib/request.rb
+++ b/app/lib/request.rb
@@ -74,7 +74,12 @@ class Request

       yield response if block_given?
     rescue => e
-      raise e.class, e.message, e.backtrace[0]
+      if e.respond_to?(:message)
+        raise e.class, e.message, e.backtrace[0]
+      else
+        Rails.logger.error "Caught exception was a String: #{$@}"
+        raise e
+      end
     ensure
       http_client.close unless http_client.persistent?
     end

[ThibG]

After reading the Ruby source code quite a bit, it seems very unlikely to me that even a C extension would be able to raise a String.

Looking at the raise e.class, e.message, e.backtrace[0] line, I have another theory: it is possible that the caught exception features a constructor that differs from “regular” exceptions, expecting, for instance, an Exception object instead of a string.

Indeed, consider the following example:

class WrappedException < StandardError
  def initialize(e)
    super(e.message)
  end
end

begin
  raise WrappedException.new(StandardError.new("foo"))
rescue => e
  raise e.class, e.message, e.backtrace[0]
end

This will fail because raise WrappedException, "foo", "42" is roughly equivalent to raise (WrappedException.new("foo"), "42"), which would fail with “undefined method `message' for "foo":String (NoMethodError)”

Now, the backtrace seem to indicate this comes from our code, and not the constructor, but this might very well be because of Rails' Backtrace Cleaner. Editing config/initializers/backtrace_silencers.rb to remove it might confirm this suspicion.

[ThibG]

Yup, Seahorse::ClientClient::NetworkingError works exactly like that:

https://github.com/aws/aws-sdk-ruby/blob/9257098cfd8a386e5424f998fcb5cd2d11222a1a/gems/aws-sdk-core/lib/seahorse/client/networking_error.rb#L3-L9