Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Already on GitHub? Sign in to your account

Thin not logging in development environment #454

Closed
canton7 opened this Issue Jan 19, 2012 · 12 comments

Comments

Projects
None yet
4 participants

canton7 commented Jan 19, 2012

In Sinatra 1.3.2 onwards, no logging output is produced when using thin as the webserver. Versions 1.3.1 and 1.3.0 work as expected.

This only occurs when the environment is set to development -- production and testing behave as expected.

Logging can be restored by adding the line use Rack::CommonLogger to the app.
Under the other environments, this results in two log messages being produced for each event.

canton7 commented Jan 19, 2012

To add to the "only breaks in development" assertion:

When the environment is set using either set :environment, :production/:testing, or by running the app with ruby myapp.rb -e production/testing, logging doesn't work.

When the environment is passed directly to thin, using a minimal config.ru and thin start -e production/testing, logging works.

Yes, i'm having this trouble too and i'm using the workaround that @canton7 told in the first comment.

I think this bug came from this change:

  • Don't automatically add Rack::CommonLogger if Rack::Server is adding it,
    too. (Konstantin Haase)

canton7 commented Jan 20, 2012

Confirmed that logging works in b95764b: "remove unnecessary parens from example", and is broken in bf3ad8c: "rework logger setup".

It appears that the code assumes that Rack::Server will provide a logger if ENV['RACK_ENV'] is "development".
Apparently this assumption is false, for thin at least.
Unfortunately I don't know enough about Rack to provide a better test, though.

auxbuss commented Mar 4, 2012

I got bitten by this today. The problem seems to be here:

      def setup_logging(builder)
        if logging?
          setup_common_logger(builder)
          setup_custom_logger(builder)
        elsif logging == false
          setup_null_logger(builder)
        end
      end

      def setup_null_logger(builder)
        builder.use Rack::NullLogger
      end

      def setup_common_logger(builder)
        return if ["development", "deployment", nil].include? ENV["RACK_ENV"]
        builder.use Rack::CommonLogger
      end

      def setup_custom_logger(builder)
        if logging.respond_to? :to_int
          builder.use Rack::Logger, logging
        else
          builder.use Rack::Logger
        end
      end

but, beyond the null logger, it's not clear to me what this is actually trying to achieve; so it's difficult to suggest a fix.

Are there any tests for this area? Because I couldn't find any.

I do, however, believe that documenting the intention, clearly and with examples, would help a lot. I've written my own loggers for now, and patched the code, because I cannot understand the intent. There seems to be general confusion about logging in sinatra judging from a quick google on the issue.

Yeah, i see the code too and i think the same. It's not very clear, and i can't understand this particular line:

return if ["development", "deployment", nil].include? ENV["RACK_ENV"]

Why the common logger hasn't been set up if the app is in development environment?

Maybe someone of the core team knows the answer

canton7 commented Mar 4, 2012

If I recall, and I could be mistaken, some servers (not thin) add CommonLogger on their own when in development mode. It also appears to be very hard to determine whether CommonLogger has been attached or not, requiring the hack which @carloslopes noted. Thin break this assumption, hence why logging using thin in development is broken.

Of course, I could be vastly mistaken about this (the code isn't massively clear to follow). However, if this is the issue, I can't see an easy solution, other than a big lookup table of which servers provide logging where.

@canton7 Yeah, but in my opinion the code shouldn't rely on the servers to set up or not the CommonLogger.

canton7 commented Mar 5, 2012

@carloslopes I completely agree with you.

So, i think that sinatra should choose one of these two options:

  • Force the set up of CommonLogger (and in some cases this will be duplicated because the server already set it up);
  • Or remove the set up of CommonLogger passing the responsability to the server / developer.
Owner

rkh commented Mar 7, 2012

The issues is that Rack sets up (or used to?) CommonLogger on its own, so we had a double logging effect in development mode. Writing a test for this right now, so I can have it run against different Rack versions.

@rkh rkh closed this in a0adda9 Mar 8, 2012

canton7 commented Mar 9, 2012

Thanks!

nice!

danieldreier pushed a commit to danieldreier/sinatra that referenced this issue Nov 10, 2017

prevent double-logging only on webrick, fixes #454
Conflicts:

	test/integration/app.rb
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment