Crystal: Nil assertion failed (NilAssertionError) Crystal says I found a bug in the compiler, so I am reporting it

[phangs]

wilbert@wilbert-UX360CAK:~/Documents/Development/crystal/blog$ crystal ./src/blog.cr
Nil assertion failed (NilAssertionError)
  from ???
  from ???
  from ???
  from ???
[snipped]
  from ???
  from ???
  from ???
  from ???
Error: you've found a bug in the Crystal compiler. Please open an issue, including source code that will allow us to reproduce the bug: https://github.com/crystal-lang/crystal/issues

```cr
require "granite/adapter/pg"

module Blog::Models
class User < Granite::Base
connection Pg
include CrSerializer(JSON)

  table "users"

  column id : Int64, primary: true
  column first_name : String
  column last_name : String
  column email : String
  column password : String
  column created_at : Time
  column updated_at : Time
  column deleted_at : Time
end

end

[rdp]

Could you fix the formatting here please? Also is there a smaller sample that reproduces the problem (like an isolated version)?

[Blacksmoke16]

This is most likely some Granite issue in that he's using a getter for some field that is still nil. However, what's interesting is that it says its a compiler bug...

EDIT: It's most likely _NOT_ a Granite bug, but more so something caused within Athena when TBD. I'll work on getting a smaller reproducible sample. However based on the stack trace it seems the root cause is that https://github.com/crystal-lang/crystal/blob/master/src/compiler/crystal/semantic/main_visitor.cr#L1015 typed_def.block_arg is nil.

Maybe @asterite has an idea?

Nil assertion failed (NilAssertionError)
  from ~crystal/src/nil.cr:106:5 in 'not_nil!'
  from ~crystal/src/compiler/crystal/semantic/main_visitor.cr:1015:26 in 'visit'
  from ~crystal/src/compiler/crystal/syntax/visitor.cr:27:12 in 'accept'
  from ~crystal/src/compiler/crystal/semantic/main_visitor.cr:1121:7 in 'visit'
  from ~crystal/src/compiler/crystal/syntax/visitor.cr:27:12 in 'accept'
  from ~crystal/src/compiler/crystal/semantic/main_visitor.cr:1042:13 in 'visit'
  from ~crystal/src/compiler/crystal/syntax/visitor.cr:27:12 in 'accept'
  from ~crystal/src/compiler/crystal/semantic/main_visitor.cr:1308:21 in 'visit'
  from ~crystal/src/compiler/crystal/syntax/visitor.cr:27:12 in 'accept'
  from ~crystal/src/compiler/crystal/syntax/ast.cr:169:27 in 'accept_children'
  from ~crystal/src/compiler/crystal/syntax/visitor.cr:28:11 in 'accept'
  from ~crystal/src/compiler/crystal/semantic/call.cr:422:13 in 'instantiate'
  from ~crystal/src/compiler/crystal/semantic/call.cr:311:5 in 'lookup_matches_in_type'
  from ~crystal/src/compiler/crystal/semantic/call.cr:260:3 in 'lookup_matches_in_type:search_in_parents:with_literals'
  from ~crystal/src/compiler/crystal/semantic/call.cr:239:5 in 'lookup_matches_in'
  from ~crystal/src/compiler/crystal/semantic/call.cr:238:3 in 'lookup_matches_in:with_literals'
  from ~crystal/src/compiler/crystal/semantic/call.cr:203:7 in 'lookup_matches_without_splat'
  from ~crystal/src/compiler/crystal/semantic/call.cr:130:7 in 'lookup_matches:with_literals'
  from ~crystal/src/compiler/crystal/semantic/call.cr:119:5 in 'lookup_matches'
  from ~crystal/src/compiler/crystal/semantic/call.cr:91:5 in 'recalculate'
...

[Blacksmoke16]

Reduced https://play.crystal-lang.org/#/r/81iw

Is an issue that seems to be caused by using Crylog and Granite together.

require "logger"

module Crylog
  struct Logger
    def initialize(@channel : String); end

    def debug(message)
      debug do
        message.to_s
      end
    end

    def debug(&block : -> String) : Nil
      log &block
    end

    private def log(&block : -> String) : Nil
    end
  end
end

class Crylog::CrylogLogger < ::Logger
  @logger : Crylog::Logger

  def initialize(channel : String = "main")
    @logger = Crylog::Logger.new channel
    super nil
  end

  def debug(message) : Nil
    @logger.debug message
  end

  def debug(&block : -> String) : Nil
    @logger.debug &block
  end
end

module Granite::Settings
  class_property logger : ::Logger = ::Logger.new nil
end

Granite::Settings.logger = Crylog::CrylogLogger.new
Granite::Settings.logger.debug { "hello" }

Seems to be an issue with captured blocks and type restrictions?

[asterite]

I think the problem is capturing a block in one overload, yielding in another:

class Foo
  def method
    yield
  end
end

class Bar
  def method(&block)
    block
  end
end

foo = Foo.new || Bar.new
foo.method { }

This is a known bug (for me :-P), I still don't know how to fix it. But workaround: either always capture blocks or always yield, but never mix them.

[Blacksmoke16]

Hmm yea, I guess in my case the yield comes from ::Logger methods log(Severity::{{name.id}}, progname) { yield }, but in my case it wouldn't be possible for it to be executed since they're being overridden in the child class.

IMO this issue would be solved if we had/relied more upon interfaces as the Logger type wouldn't be tied to an implementation of it.

Ref #8147 and #5874

EDIT: Without an interface I don't have any ideas on how fix this. I.e. having a custom logger implementation that is compatible with the standard libraries'.

EDIT2: I guess the temporary fix would be to override Granite::Settings to make the type of Logger be Crylog::CrylogLogger if you're going to be using Crylog :/

EDIT3: No that doesn't seem to work...

[straight-shoota]

@asterite Care to make an issue for that so others can know that bug, too? ;)

[asterite]

It seems to be https://github.com/crystal-lang/crystal/issues/5299

[asterite]

though the title is too restrictive... sorry, I don't have much time these days for Crystal other than replying to things I see on the go

[Blacksmoke16]

For future reference I think I can solve it by yielding in the wrapped ::Logger type, but capturing the block in the custom implementation type. It's not _as_ ideal since the block would be executed twice, but I suppose that's better than it not compiling at all.

https://play.crystal-lang.org/#/r/81me

The other option would be not supporting one or the other logging methods, which is even less ideal as then it would no longer be a drop in replacement.

cc @didactic-drunk What are your thoughts on this approach? Any better ideas?

[asterite]

@Blacksmoke16 Just to understand a bit more the problem and what we can do about it: do you need to capture the block in the debug method, or you just need to forward it to another method that will execute the block right away?

I ask because I'm thinking that if a method does yield, if you want to overload that in a union or in the same hierarchy you probably want to yield in those cases too. It would be strange if one method yielded but the other one captured the block. So I'm thinking we should disallow mixing these two behaviors. The compiler will say "this overload yields, but this other captures the block: make sure all overloads yield or all capture". In logger's case it will be a bit more efficient because you'd want to always inline the block because it should be called right away.

[asterite]

Looking at https://github.com/Blacksmoke16/crylog/pull/9/files it seems like yes, you was just forwarding the block.

I guess once we make it so that &block means a captured block and & means a non-captured block, the only way to forward a non-captured block is by using yield it will be harder to bump into this issue.

[Blacksmoke16]

@asterite Yea the goal of the CrylogLogger class was to wrap the stdlib's ::Logger type (so that it can be used with variables typed as ::Logger, while basically forwarding the messages to the Crylog::Logger custom implementation.

I ideally would just capture the block and pass it on to the custom implementation method which stores it in a Crylog::Message here. The idea behind that is based on https://github.com/Blacksmoke16/crylog/pull/6 to make the block not be executed if the severity less than the minimum severity; mainly for performance reasons as @didactic-drunk showed in the PR description.

I guess once we make it so that &block means a captured block and & means a non-captured block, the only way to forward a non-captured block is by using yield it will be harder to bump into this issue.

This would be a nice to have. I would say my PR is just a workaround as it kinda defeats the intention since the block can be executed twice, which is better than it not compiling at least.