search

anycable / anycable-rails

AnyCable for Ruby on Rails applications
https://anycable.io
MIT License
499 stars 35 forks source link

log4r broken in development #170

Closed subashkc closed 2 years ago

subashkc commented 2 years ago

First off all, thank you for all the hard work for the gem, love the performance it provides with seamless transition from actioncable,

Tell us about your environment

Ruby version: ruby 2.7.3p183

Rails version: Rails 6.0.4.4

anycable gem version: 1.2.2

anycable-rails gem version: 1.3.2

grpc gem version: 1.45.0

I did the migration from actioncable without any but 1 issue involving log4r, we use log4r to write logs to a logfile in all environments instead of logging it to STDOUT and when I start the server it fails with the stacktrace below

17:54:58 rpc.1       | undefined method `formatter' for #<Log4r::Logger:0x0000555b0a7a4968>
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/activesupport-6.0.4.4/lib/active_support/tagged_logging.rb:66:in `new'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-rails-1.3.2/lib/anycable/rails/railtie.rb:23:in `block (2 levels) in <class:Railtie>'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/lib/anycable/cli.rb:173:in `each'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/lib/anycable/cli.rb:173:in `configure_server!'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/lib/anycable/cli.rb:52:in `run'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/bin/anycable:7:in `<top (required)>'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/anycable:23:in `load'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/anycable:23:in `<top (required)>'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli/exec.rb:63:in `load'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli/exec.rb:63:in `kernel_load'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli/exec.rb:28:in `run'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli.rb:476:in `exec'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli.rb:30:in `dispatch'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/base.rb:476:in `start'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli.rb:24:in `start'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/libexec/bundle:46:in `block in <top (required)>'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/friendly_errors.rb:123:in `with_friendly_errors'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/libexec/bundle:34:in `<top (required)>'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/bundle:23:in `load'
17:54:58 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/bundle:23:in `<main>'

If I comment out the log4r config from application.rb it works without any issues, log4r config is pretty standard, pasted below

log4r_config:
  loggers:
    - name      : production
      level     : INFO
      trace     : 'false'
      outputters :
      - logfile
    - name      : development
      level     : DEBUG
      trace     : 'true'
      outputters :
      - logfile
    - name      : qa
      level     : INFO
      trace     : 'true'
      outputters :
      - logfile
    - name      : uat
      level     : INFO
      trace     : 'true'
      outputters :
      - logfile

  outputters:
  - type: FileOutputter
    name: logfile
    trunc: 'false'
    filename: 'log/wilberforce000001.log'
    formatter:
      date_pattern: '%Y-%m-%d %H:%M:%S'
      pattern     : '%d %l: %m '
      type        : PatternFormatter

application.rb has the following to initialize the logger

    log4r_config = YAML.load_file(File.join(File.dirname(__FILE__),"log4r.yml"))
    YamlConfigurator.decode_yaml( log4r_config['log4r_config'] )
    config.logger = Log4r::Logger[Rails.env]

Please let me know if there is a way to turn off logging out to STDOUT in development or if I am doing something incorrectly.

palkan commented 2 years ago

Thanks for the report!

I pushed a quick fix to master, could you please try it?

subashkc commented 2 years ago

@palkan Thanks for the quick response, I still get the same error message about undefined method formatter

palkan commented 2 years ago

@subashkc Could you please provide a stack trace?

subashkc commented 2 years ago 
22:11:16 rpc.1       | undefined method `formatter' for #<Log4r::Logger:0x000055e9d44143d0>
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/bundler/gems/anycable-rails-93786192b222/lib/anycable/rails/railtie.rb:29:in `block (2 levels) in <class:Railtie>'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/lib/anycable/cli.rb:173:in `each'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/lib/anycable/cli.rb:173:in `configure_server!'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/lib/anycable/cli.rb:52:in `run'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/anycable-core-1.2.2/bin/anycable:7:in `<top (required)>'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/anycable:23:in `load'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/anycable:23:in `<top (required)>'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli/exec.rb:63:in `load'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli/exec.rb:63:in `kernel_load'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli/exec.rb:28:in `run'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli.rb:476:in `exec'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli.rb:30:in `dispatch'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/vendor/thor/lib/thor/base.rb:476:in `start'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/cli.rb:24:in `start'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/libexec/bundle:46:in `block in <top (required)>'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/2.7.0/bundler/friendly_errors.rb:123:in `with_friendly_errors'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/libexec/bundle:34:in `<top (required)>'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/bundle:23:in `load'
22:11:16 rpc.1       | /home/leonidas/.rbenv/versions/2.7.3/bin/bundle:23:in `<main>'
palkan commented 2 years ago

Thanks! Pushed another fix.

subashkc commented 2 years ago

yep, works now, Thanks for the quick fix. :+1: