Nil pointer dereference about anycable-go

[palkan]

Looks like RPC call failed. Can you, please, provide me with RPC server logs? (To turn on verbose logging start it with ANYCABLE_DEBUG=1 ./bin/anycable).

Also, which versions of anycable-go and anycable gem do you use?

[danini-the-panini]

I'm using the latest versions of everything at the time of this writing.

Looks like the problem isn't with anycable-go (should probably move this anycable-rails then)

Looking at the debug output, there's a problem with me logging with the user email as a tag:

$ ANYCABLE_DEBUG=1 be ruby bin/anycable                                                                                        130 ↵
I, [2017-01-31T22:10:39.510844 #43649]  INFO -- : handling /anycable.RPC/Connect with #<Method: Anycable::RPCHandler#connect>
I, [2017-01-31T22:10:39.510948 #43649]  INFO -- : handling /anycable.RPC/Command with #<Method: Anycable::RPCHandler#command>
I, [2017-01-31T22:10:39.510980 #43649]  INFO -- : handling /anycable.RPC/Disconnect with #<Method: Anycable::RPCHandler#disconnect>
I, [2017-01-31T22:10:39.511046 #43649]  INFO -- : RPC server is listening on localhost:50051
I, [2017-01-31T22:10:42.291773 #43649]  INFO -- : waiting: 0, max: 20
I, [2017-01-31T22:10:42.291889 #43649]  INFO -- : deadline is 1970-01-01 01:59:59 +0200; (now=2017-01-31 22:10:42 +0200)
I, [2017-01-31T22:10:42.292013 #43649]  INFO -- : schedule another job
D, [2017-01-31T22:10:42.293688 #43649] DEBUG -- : RPC Connect: #<Anycable::ConnectionRequest:0x007f96fd4e1ba0>
W, [2017-01-31T22:10:42.344544 #43649]  WARN -- : failed handler: #<GRPC::ActiveCall:0x007f96fd4e1f60>; sending status:UNKNOWN
W, [2017-01-31T22:10:42.344597 #43649]  WARN -- : undefined method `add_tags' for #<ActiveSupport::Logger:0x007f96feb5a760> (NoMethodError)
/Users/daniel/Projects/fuza17/app/channels/application_cable/connection.rb:7:in `connect'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/anycable-rails-0.4.3/lib/anycable/rails/actioncable/connection.rb:42:in `handle_open'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/anycable-0.4.2/lib/anycable/rpc_handler.rb:19:in `connect'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_desc.rb:71:in `call'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_desc.rb:71:in `run_server_method'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:368:in `block in loop_handle_server_calls'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:132:in `block in loop_execute_jobs'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:129:in `loop'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:129:in `loop_execute_jobs'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:82:in `block (2 levels) in start'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:81:in `catch'
/Users/daniel/.rbenv/versions/2.3.3/lib/ruby/gems/2.3.0/gems/grpc-1.0.1-universal-darwin/src/ruby/lib/grpc/generic/rpc_server.rb:81:in `block in start'

This comes from my application connection:

module ApplicationCable
  class Connection < ActionCable::Connection::Base
    identified_by :current_user

    def connect
      self.current_user = find_verified_user
      logger.add_tags 'ActionCable', current_user.email
    end

    protected

    def find_verified_user # this checks whether a user is authenticated with devise
      if verified_user = User.find_by(id: cookies.signed["user.id"])
        verified_user
      else
        reject_unauthorized_connection
      end
    end
  end
end

[danini-the-panini]

I've solved my problem for the time being. Commenting out that line solves the error.

I had another issue, that my messages weren't being received by my clients (except for pings and the usual actioncable messages). But I resolved it by putting my initial broadcasts in a thread that runs a second after subscribing to a channel.