Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

[2.1] Logging levels configuration in application.conf is ignored in production mode (dist) #1186

Merged
merged 1 commit into from
@monzonj

The following login configuration in application.conf works in DEV mode but not in a DIST. release:

logger.root=DEBUG
logger.play=DEBUG
logger.application=DEBUG

These loggin levers are loaded into logback in the Application.scala class

   Logger.configure(
      Map("application.home" -> path.getAbsolutePath),
      configuration.getConfig("logger").map { loggerConfig =>
        loggerConfig.keys.map {
          case "resource" | "file" | "url" => "" -> null
          case key @ "root" => "ROOT" -> loggerConfig.getString(key, Some(validValues)).map(setLevel).get
          case key => key -> loggerConfig.getString(key, Some(validValues)).map(setLevel).get
        }.toMap
      }.getOrElse(Map.empty),
      mode)

However this configuration gets replaced by this other code in the Server trait when running in DIST. mode:

  // Configure the logger for the first time
  Logger.configure(
    Map("application.home" -> applicationProvider.path.getAbsolutePath),
    mode = mode)

The logger is reset and all config is lost.

As I understand it, the Server trait constructor should be loaded before Application.scala, but it seems it is the other way around.

@galderz

I had that issue when integrating Play on top of Escalante. Play was clearing all base logging set up. I did workaround it by caching the settings, starting the application, and the resetting them again. Hacky but kinda works. I'd love to see more sane logging in Play...

@monzonj

Hey @galderz I've been trying to also reset the log levels by calling again the Logger.configure(...) after the startup. But I cannot figure where to do this. Even overriding the play.api.GlobalSettings.onStart method it won't take it.

Where do you do the resetting?

((I just find very annoying having to keep yet another config file -logback.xml- for DIST. releases, application.conf should be enough))

@galderz

I do the resetting here. Basically, take all logging handlers, cache them and then reapply them here, once the application has started.

I dunno how you'd do the same on an end-user application though. You can deploy Play apps on top Escalante and hence we did some work to control their lifecycle, which gives us the chance to do things like this.

@nraychaudhuri
Collaborator

The reset in production mode happens because play ships with it logger.xml file https://github.com/playframework/Play20/blob/master/framework/src/play/src/main/resources/logger.xml

I need to investigate why play is shipping its own logger.xml file maybe we can get ride of it. One workaround would be to specify your own application-logger.xml file in prod mode.

@mslinn

I have been bitten by this issue as well. I am presently providing a custom logger configuration via

export JAVA_OPTS="-Dlogger.file=conf/application-logger.xml"

...but this is suboptimal.

@toddobryan

I'm suffering through this as well. The net result of this bug seems to be that all mention of logger settings has been removed from the 2.1.x and 2.2.x documentation.

Is the only way to get logging levels different from the default in production to provide a command-line argument with a path to a custom application-logger.xml file?

@serphacker

Very annoying issue, by the way using -Dlogger.file doesn't works with 2.1.3, so there is totally no way to have log configuration in prod mode without hacking source code

@seantbrady

Putting application-logger.xml in your /conf directory should work without a command line argument.

@serphacker

@seantbrady yes it will work, but just one second, after, the logger is reset and all config is lost, that's where is the problem.

@damianball

@serphacker, I'm using Play 2.1.4 and I've added an application-logger.xml file into my conf directory. After setting the application log level to INFO and deploying to production... my configuration changes seems to be stable.

Still... the documentation requires some updating. I was confused for about 30 minutes before I found this issue page and this one on google groups (https://groups.google.com/forum/#!topic/play-framework/cAvr2vRtyI0).

Thanks!

@huntc
Owner

Is there anyone that can quickly confirm whether this is a 2.2.x issue also? If so then we may deal with this the same way we dealt with overriding ehcache configuration i.e. we provide a default configuration given an irregular name thus if the user provides a regular name then it succeeds in terms of priority.

If it is a 2.1.x issue then we may be able to do something here, but given that 2.2.x is out, probably only as a customer support request.

@ericMK

I'm also seeing this issue in 2.2.0-RC2. mslinn's -Dlogger.file=conf/application-logger.xml flag workaround is getting me by, thanks Mike! Please do fix as I spent a day trying things, reseaching, etc. and we all want to see Play succeed, not frustrating users.

@mits430

Confirmed that the workaround works! I really appreciate it.

@monzonj

Yes, still happening in 2.2.

You can do that hack with the filenames, but really, I don't get what the big deal is. The trait Server.scala has a bug that prevents the proper Logger initialization. Why not fixing that?

Replace:

  // Configure the logger for the first time
  Logger.configure(
    Map("application.home" -> applicationProvider.path.getAbsolutePath),
    mode = mode)

With:

   Logger.configure(
      Map("application.home" -> path.getAbsolutePath),
      configuration.getConfig("logger").map { loggerConfig =>
        loggerConfig.keys.map {
          case "resource" | "file" | "url" => "" -> null
          case key @ "root" => "ROOT" -> loggerConfig.getString(key, Some(validValues)).map(setLevel).get
          case key => key -> loggerConfig.getString(key, Some(validValues)).map(setLevel).get
        }.toMap
      }.getOrElse(Map.empty),
      mode)

((You might want to do some re-factoring because the code above also exists in Application.scala, which is correctly setting up the logger))

@nremond

@huntc will something be done?

@huntc
Owner

@nremond Would you like to try and tackle the issue via a PR? :-)

@makoConstruct

I don't know if this is the same issue, but I'm finding that standalone dists actually ignore the configuration file conf/application.conf in favour of another application.conf that's bundled inside the lib/.--SNAPSHOT.jar file.

@jroper jroper Ensure appplication.conf log configuration works in prod
Fixes #1186.

The logger is configured in the constructor of Application.  However, it
was also being configured in the constructor of Server, this was so that
in dev mode, when the server first started up, before any application
existed, the default (or overridden default) configuration is applied.
The problem was, this was overriding the config done in Application,
since in prod mode, the server is instantiated after the application.

So, I moved the dev mode logging configuration concerns into
ReloadableApplication, which is instantiated during the instantiation of
the server in dev mode, and so effectively happens at the same time as
it used to.
26e6cbf
@jroper
Owner

Pull request attached, commit message repeated here:

The logger is configured in the constructor of Application. However, it was also being configured in the constructor of Server, this was so that in dev mode, when the server first started up, before any application existed, the default (or overridden default) configuration is applied. The problem was, this was overriding the config done in Application, since in prod mode, the server is instantiated after the application.

So, I moved the dev mode logging configuration concerns into ReloadableApplication, which is instantiated during the instantiation of the server in dev mode, and so effectively happens at the same time as it used to.

Backport to 2.3.x required.

@jroper jroper added this to the 2.3.3 milestone
@jroper jroper self-assigned this
@pvlugter pvlugter merged commit d5f3bfd into from
@jroper jroper referenced this pull request from a commit
@jroper jroper Ensure appplication.conf log configuration works in prod
Fixes #1186.

The logger is configured in the constructor of Application.  However, it
was also being configured in the constructor of Server, this was so that
in dev mode, when the server first started up, before any application
existed, the default (or overridden default) configuration is applied.
The problem was, this was overriding the config done in Application,
since in prod mode, the server is instantiated after the application.

So, I moved the dev mode logging configuration concerns into
ReloadableApplication, which is instantiated during the instantiation of
the server in dev mode, and so effectively happens at the same time as
it used to.
f112290
@pvlugter
Owner

2.3.x backport: f112290

@jroper jroper deleted the branch
@jroper jroper referenced this pull request
Closed

Sort out logging in tests #1717

@cdraeger cdraeger referenced this pull request from a commit in cdraeger/playframework
@jroper jroper Ensure appplication.conf log configuration works in prod
Fixes #1186.

The logger is configured in the constructor of Application.  However, it
was also being configured in the constructor of Server, this was so that
in dev mode, when the server first started up, before any application
existed, the default (or overridden default) configuration is applied.
The problem was, this was overriding the config done in Application,
since in prod mode, the server is instantiated after the application.

So, I moved the dev mode logging configuration concerns into
ReloadableApplication, which is instantiated during the instantiation of
the server in dev mode, and so effectively happens at the same time as
it used to.
1546f47
@SRGOM

I still see this in 2.3.7, not sure what I'm doing wrong.
I've tried various combination of logger.application in application.conf and have an application-logger.xml and logger.xml inside of conf

Dev works just fine but prod doesn't. Here's my activator command:
activator -Dlogger.file=./conf/application-logger.xml -Dhttps.port=9443 -Dhttp.port=9000 "start"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Commits on Aug 7, 2014
  1. @jroper

    Ensure appplication.conf log configuration works in prod

    jroper authored
    Fixes #1186.
    
    The logger is configured in the constructor of Application.  However, it
    was also being configured in the constructor of Server, this was so that
    in dev mode, when the server first started up, before any application
    existed, the default (or overridden default) configuration is applied.
    The problem was, this was overriding the config done in Application,
    since in prod mode, the server is instantiated after the application.
    
    So, I moved the dev mode logging configuration concerns into
    ReloadableApplication, which is instantiated during the instantiation of
    the server in dev mode, and so effectively happens at the same time as
    it used to.
This page is out of date. Refresh to see the latest.
View
13 framework/src/play-server/src/main/scala/play/core/server/Server.scala
@@ -11,7 +11,6 @@ import play.api.mvc._
import scala.concurrent.duration._
import scala.util.{ Try, Success, Failure }
-import scala.util.control.NonFatal
import scala.concurrent.Future
trait WebSocketable {
@@ -24,18 +23,6 @@ trait WebSocketable {
*/
trait Server {
- // First delete the default log file for a fresh start (only in Dev Mode)
- try {
- if (mode == Mode.Dev) new java.io.File(applicationProvider.path, "logs/application.log").delete()
- } catch {
- case NonFatal(_) =>
- }
-
- // Configure the logger for the first time
- Logger.configure(
- Map("application.home" -> applicationProvider.path.getAbsolutePath),
- mode = mode)
-
val bodyParserTimeout = {
//put in proper config
1 second
View
15 framework/src/play/src/main/scala/play/core/system/ApplicationProvider.scala
@@ -85,6 +85,21 @@ class ReloadableApplication(buildLink: BuildLink, buildDocHandler: BuildDocHandl
}
}
+ // First delete the default log file for a fresh start (only in Dev Mode)
+ try {
+ new java.io.File(path, "logs/application.log").delete()
+ } catch {
+ case NonFatal(_) =>
+ }
+
+ // Configure the logger for the first time.
+ // This is usually done by Application itself when it's instantiated, which for other types of ApplicationProviders,
+ // is usually instantiated along with or before the provider. But in dev mode, no application exists initially, so
+ // configure it here.
+ Logger.configure(
+ Map("application.home" -> path.getAbsolutePath),
+ mode = Mode.Dev)
+
lazy val path = buildLink.projectPath
println(play.utils.Colors.magenta("--- (Running the application from SBT, auto-reloading is enabled) ---"))
Something went wrong with that request. Please try again.