I may have found a bug with `previous_def`, but not sure

Help & Support
1

Hey friends, I’m seeing what I think is a bug but I’m not sure. If it is a bug, I’m not sure whether it’s in Crystal itself, crystal-db, or crystal-pg.

I’ve been working on an instrumentation tool to report APM traces to Datadog and I’m trying to instrument existing tools by redefining methods to wrap their method bodies in calls to Datadog.tracer.trace. For example:

class HTTP::Client
  def exec(request : HTTP::Request) : HTTP::Client::Response
    Datadog.tracer.trace "http.request", resource: "#{request.method} #{request.resource}" do |span|
      previous_def
    end
  end
end

In everything I’ve been testing, this works great … except in DB::QueryMethods:

module DB::QueryMethods
  def query(query, *args_, args : Array? = nil) : DB::ResultSet
    Datadog.tracer.trace "db.query", resource: query do |span|
      previous_def
    end
  end
end

This returns this error at runtime:

Unhandled exception: bind message supplies 1 parameters, but prepared statement "" requires 2 (PQ::PQError)

At first I thought I’d just screwed something up and accidentally passed only 1 arg in the array, but I tried pping all the method args and it definitely shows 2 args in the array:

{query:
  "SELECT closings.id, closings.company_id, closings.file_number, closings.status, closings.documents_status, closings.slug, closings.source, closings.created_at, closings.updated_at FROM closings WHERE (closings.created_at > $1) AND (closings.created_at < $2) ",
 splat: {},
 array:
  [2020-10-16 02:44:49.868728000 -04:00 Local,
   2020-10-16 14:44:49.868740000 -04:00 Local]}

And, in fact, it still fails if all I do is have it call previous_def:

module DB::QueryMethods
  def query(query, *args_, args : Array? = nil) : DB::ResultSet
    # pp query: query, splat: args_, array: args
    previous_def
  end
end

But if I replace previous_def with the actual body of that method, it works just fine. So it makes me think it’s a bug with previous_def, but the fact that it’s apparently changing how many args are in the array seems like it could be something in crystal-db.

Another thing to note is that this is the only thing I’ve tried this with that is a module that gets mixed into other classes. The other things I’ve been adding instrumentation to have been classes.

2

Yes, try this:

def foo(x, *args, other = 1)
  p! x, args, other
end

def foo(x, *args, other = 1)
  previous_def
end

foo(1, 2, 3, other: 4)

Output:

x     # => 1
args  # => {2, 3, 4}
other # => 1

Expected output:

x     # => 1
args  # => {2, 3}
other # => 4

What happens if in your example you explicitly pass the arguments to previous_def? I think that should work (though I’d still report the bug)

1 Like
3

I fixed it here: https://github.com/crystal-lang/crystal/pull/9834

Can you try compiling a compiler at that PR and seeing if it solves the problem for you?

2 Likes
4

Whoa, this is impressive debugging! And your PR works! :100:

Seems like it was the combination of splat args followed by an arg with a default value? I honestly didn’t know some of these semantics around splat args. I did try passing the args explicitly, but I was passing them the way it was expanding them automatically, so with your explanation in the PR it makes a lot more sense now why that wasn’t working! I thought I was losing it trying to get that working last night! :smile:

Thank you so much!

5

Cool! And just in case I wasn’t clear: you can explicitly pass arguments to previous_def as a workaround to the bug.

2 Likes