Re: [sbt] Java logging config property being ignored

[Indrajit Raychaudhuri]

Should work.

Could you try doing something like this and printing the system property in you code just to verify?

fork := true
javaOptions += "-Dtest.foo=MyTestFoo"

If this works, could it be possible that logging.properties is not the the regular (classpath based) lookup location?

- Indrajit


On Dec 25, 2012, at 7:50 PM, Sam Halliday <sam.ha...@gmail.com> wrote:

> Hi all,
>
> I'm trying to get SBT to use my Java Logging config setup, with the following
>
> fork := true
>
> javaOptions += "-Xmx2G"
>
> javaOptions += "-Djava.util.logging.config.file=logging.properties"
>
> outputStrategy := Some(StdoutOutput)
>
>
> But the logging properties are being ignored and I'm seeing the behaviour I would expect from the default logging setup. I've confirmed that my logging.properties file is sensible as it works fine from ntelliJ.
>
> I'm concerned that my other Java properties are also being ignored.
>
> What am I doing wrong?
>
> I'm using SBT 0.12.1
>
> --
> You received this message because you are subscribed to the Google Groups "simple-build-tool" group.
> To view this discussion on the web visit https://groups.google.com/d/msg/simple-build-tool/-/XRaKsNl6ifEJ.
> To post to this group, send email to simple-b...@googlegroups.com.
> To unsubscribe from this group, send email to simple-build-t...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/simple-build-tool?hl=en.

[Som Snytt]

On Tue, Dec 25, 2012 at 5:50 PM, Sam Halliday <sam.ha...@gmail.com> wrote:

I'm concerned that my other Java properties are also being ignored.

What am I doing wrong?

Resource files are in src/main/resources by default, right?

[Sam Halliday]

Not Java properties – they are relative to the JVM working directory.

[Sam Halliday]

Indrajit,

I checked this and the property does seem to be making it through. The working directory is also what I expected, so I'm just really confused.

How could I edit the following

  javaOptions += "-Djava.util.logging.config.file=logging.properties"

so that "projectBaseDir + logging.properties" is passed?

Or is there something more subtle at work regarding Logging when SBT starts up a JVM?

[Sam Halliday]

Closing a loop (but still outstanding, but more details on this project):

  https://github.com/fommil/scala-java-logging/issues/2

[Sam Halliday]

Actually, here is a solid example of the bug. Clone the scala-java-logging repo and create the following file:

import akka.contrib.jul.JavaLogging

import java.io.File

object Scratch extends App with JavaLogging {

  log.warning(System.getProperty("java.util.logging.config.file"))

  log.warning(new File(".").getAbsolutePath)

}

then run it. Note that the Java logger is using the default logging properties, not the ones supplied by the bundled properties file.

If run from IntelliJ, with the same properties passed to the JVM, the logger uses the bundled properties file and looks much prettier.

[Indrajit Raychaudhuri]

The fact that `log.warning(System.getProperty("java.util.logging.config.file"))` prints the value of "java.util.logging.config.file", implies that your `javaOptions` settings are correct.

So the suspect to me is what you have *inside* logging.properties. Since you have set the handler to j.u.l.ConsoleHandler and you have `fork := true`, is outputStrategy [1] of some interest?

Since you had asked:

How could I edit the following

  javaOptions += "-Djava.util.logging.config.file=logging.properties"

so that "projectBaseDir + logging.properties" is passed?

You could do so, but that's not relevant here:

javaOptions <+= baseDirectory map { "-Djava.util.logging.config.file=%s/logging.properties".format(_) }

- Indrajit

[1] http://www.scala-sbt.org/release/docs/Detailed-Topics/Forking.html#configuring-output

To view this discussion on the web visit https://groups.google.com/d/msg/simple-build-tool/-/IE7lRdLkZAMJ.

[Sam Halliday]

On 31 Dec 2012, at 01:47, Indrajit Raychaudhuri wrote:

> So the suspect to me is what you have *inside* logging.properties.

The logging file is fine and works with every other java execution method I have tried (CLI, Maven, Netbeans, IntelliJ, Eclipse). None of the values from this file are being read by the Logging framework - Logging is being initialised with the system defaults.

The Java logging property file loading rules are rather bizarre. I suspect there is some interplay with how SBT launches the java binary.

> Since you have set the handler to j.u.l.ConsoleHandler and you have `fork := true`, is outputStrategy [1] of some interest?

I'm already using StdoutOutput to avoid the extra reformatting to stdout. I'd rather turn this off entirely and have my stderr appear on stderr, to be honest. Can that be achieved with None?

If SBT is using the Logger to redirect stdout / stderr, then perhaps whatever is done to enable that is interfering with the correct logging config file loading.

[Samuel Halliday]

I'm resurrecting an old thread.

To summarise the discussion so far: I'm passing

fork := true

javaOptions += "-Djava.util.logging.config.file=logging.properties"

so that my custom Java Loggers are used instead of the defaults.


To give an update – this now seems to work when running tests, but not when I run the main class.

The bizarre thing is that when I run my main class and check the parameters that are being passed to the forked JVM, my javaOptions are being respected.*

Is there anything anyone can think of that would be disrupting Java Logger's startup procedure for loading the logging config?

Indrajit had suggested that the problem might be inside the logging.properties file. I can confirm that I have used multiple configs, from trivial to non-trivial, and they all display the same issues but work perfectly fine when I manually (i.e. outside of SBT) start the main methods.


* because I have a multi-project build.scala, it is added multiple times – once for each sub project.


--
Sam

[Sam Halliday]

I updated issue 702 with a  working example of where SBT fails here

https://github.com/sbt/sbt/issues/702

[Mark Harrah]

On Thu, 4 Apr 2013 03:11:38 -0700 (PDT)
Sam Halliday <sam.ha...@gmail.com> wrote:

> I updated issue 702 with a working example of where SBT fails here
>
> https://github.com/sbt/sbt/issues/702

Ok, so the equivalent command line to what sbt runs isn't `java ...` but `scala ...` Indeed, when running your project with the `scala` command, the behavior is the same as in sbt. If you put this line in Sbt702:

println(java.lang.management.ManagementFactory.getRuntimeMXBean().getInputArguments)

you see that Scala sets up the boot classpath with a bunch of jars that aren't specified to be on the classpath. Perhaps one of the jars put on the boot classpath overrides logging somehow, but because I'm not familiar with how the logging configuration works, I would appreciate it if you could figure out why this affects things. Then, I'll follow up with the Scala project if appropriate.

-Mark

> --
> You received this message because you are subscribed to the Google Groups "simple-build-tool" group.

> To unsubscribe from this group and stop receiving emails from it, send an email to simple-build-t...@googlegroups.com.

> To post to this group, send email to simple-b...@googlegroups.com.

> Visit this group at http://groups.google.com/group/simple-build-tool?hl=en.
> For more options, visit https://groups.google.com/groups/opt_out.
>
>

[Samuel Halliday]

Hmm, interesting.

I don't have a "scala" binary installed - how do I get SBT to output the equivalent command that it's executing?

--
Sam

> You received this message because you are subscribed to a topic in the Google Groups "simple-build-tool" group.
> To unsubscribe from this topic, visit https://groups.google.com/d/topic/simple-build-tool/gKzHEwReimw/unsubscribe?hl=en.
> To unsubscribe from this group and all its topics, send an email to simple-build-t...@googlegroups.com.

[Samuel Halliday]

Mark,

I haven't been able to get very far on this... there is just too much magic going on in the scala binary and startup.

One thing that I should point out - it may be relevant - is that the "java.util.logging.config.file" property is also magical. The JVM tries to load the logging configuration really early during startup, which means that it *must* be given to the runtime binary.

I guess the reason for this magic is because one may wish to log some information before the whole classpath is loaded. Anyway, there is certainly a lot of funkiness going on inside the JUL that always looked superfluous to me, but maybe it's there for a reason.

--
Sam

On 4 Apr 2013, at 15:35, Mark Harrah <dmha...@gmail.com> wrote:

> You received this message because you are subscribed to a topic in the Google Groups "simple-build-tool" group.
> To unsubscribe from this topic, visit https://groups.google.com/d/topic/simple-build-tool/gKzHEwReimw/unsubscribe?hl=en.
> To unsubscribe from this group and all its topics, send an email to simple-build-t...@googlegroups.com.

[Mark Harrah]

On Thu, 4 Apr 2013 22:23:29 +0100
Samuel Halliday <sam.ha...@gmail.com> wrote:

> Mark,
>
> I haven't been able to get very far on this... there is just too much magic going on in the scala binary and startup.
>
> One thing that I should point out - it may be relevant - is that the "java.util.logging.config.file" property is also magical. The JVM tries to load the logging configuration really early during startup, which means that it *must* be given to the runtime binary.

That would be potentially relevant, but you can see from the printed getInputArguments that the -D... option is directly passed to the jvm. If it weren't, it wouldn't show up in that output.

-Mark

[Paul Phillips]

On Thu, Apr 4, 2013 at 2:23 PM, Samuel Halliday <sam.ha...@gmail.com> wrote:

I haven't been able to get very far on this... there is just too much magic going on in the scala binary and startup.

There's not that much magic.

% SCALA_RUNNER_DEBUG=true scala210

saved stty:

gfmt1:cflag=4b00:iflag=6902:lflag=200005cf:oflag=3:discard=ff:dsusp=19:eof=4:eol=ff:eol2=ff:erase=7f:intr=3:kill=15:lnext=16:min=1:quit=1c:reprint=12:start=11:status=14:stop=13:susp=1a:time=0:werase=17:ispeed=38400:ospeed=38400

/Library/Java/JavaVirtualMachines/jdk1.7.0_17.jdk/Contents/Home/bin/java

-Xmx256M

-Xms32M

-Xbootclasspath/a:/scala/inst/scala-2.10.1/lib/akka-actors.jar:/scala/inst/scala-2.10.1/lib/jline.jar:/scala/inst/scala-2.10.1/lib/scala-actors-migration.jar:/scala/inst/scala-2.10.1/lib/scala-actors.jar:/scala/inst/scala-2.10.1/lib/scala-compiler.jar:/scala/inst/scala-2.10.1/lib/scala-library.jar:/scala/inst/scala-2.10.1/lib/scala-partest.jar:/scala/inst/scala-2.10.1/lib/scala-reflect.jar:/scala/inst/scala-2.10.1/lib/scala-swing.jar:/scala/inst/scala-2.10.1/lib/scalap.jar:/scala/inst/scala-2.10.1/lib/typesafe-config.jar

-classpath

""

-Dscala.home=/scala/inst/scala-2.10.1

-Dscala.usejavacp=true

scala.tools.nsc.MainGenericRunner

And, to put nothing on the boot classpath.

% SCALA_RUNNER_DEBUG=true scala210 -nobootcp

saved stty:

gfmt1:cflag=4b00:iflag=6902:lflag=200005cf:oflag=3:discard=ff:dsusp=19:eof=4:eol=ff:eol2=ff:erase=7f:intr=3:kill=15:lnext=16:min=1:quit=1c:reprint=12:start=11:status=14:stop=13:susp=1a:time=0:werase=17:ispeed=38400:ospeed=38400

/Library/Java/JavaVirtualMachines/jdk1.7.0_17.jdk/Contents/Home/bin/java

-Xmx256M

-Xms32M

-classpath

/scala/inst/scala-2.10.1/lib/akka-actors.jar:/scala/inst/scala-2.10.1/lib/jline.jar:/scala/inst/scala-2.10.1/lib/scala-actors-migration.jar:/scala/inst/scala-2.10.1/lib/scala-actors.jar:/scala/inst/scala-2.10.1/lib/scala-compiler.jar:/scala/inst/scala-2.10.1/lib/scala-library.jar:/scala/inst/scala-2.10.1/lib/scala-partest.jar:/scala/inst/scala-2.10.1/lib/scala-reflect.jar:/scala/inst/scala-2.10.1/lib/scala-swing.jar:/scala/inst/scala-2.10.1/lib/scalap.jar:/scala/inst/scala-2.10.1/lib/typesafe-config.jar

-Dscala.home=/scala/inst/scala-2.10.1

-Dscala.usejavacp=true

scala.tools.nsc.MainGenericRunner

Welcome to Scala version 2.10.1 (Java HotSpot(TM) 64-Bit Server VM, Java 1.7.0_17).

Type in expressions to have them evaluated.

Type :help for more information.

scala> 

The -nobootcp option is documented in scala -help.

% scala210 -help

Usage: scala <options> [<script|class|object|jar> <arguments>]

   or  scala -help

All options to scalac (see scalac -help) are also allowed.

The first given argument other than options to scala designates

what to run.  Runnable targets are:

  - a file containing scala source

  - the name of a compiled class

  - a runnable jar file with a valid Main-Class attribute

  - or if no argument is given, the repl (interactive shell) is started

Options to scala which reach the java runtime:

 -Dname=prop  passed directly to java to set system properties

 -J<arg>      -J is stripped and <arg> passed to java as-is

 -nobootcp    do not put the scala jars on the boot classpath (slower)

Other startup options:

 -howtorun    what to run <script|object|jar|guess> (default: guess)

 -i <file>    preload <file> before starting the repl

 -e <string>  execute <string> as if entered in the repl

 -save        save the compiled script in a jar for future use

 -nc          no compilation daemon: do not use the fsc offline compiler

A file argument will be run as a scala script unless it contains only

self-contained compilation units (classes and objects) and exactly one

runnable main method.  In that case the file will be compiled and the

main method invoked.  This provides a bridge between scripts and standard

scala source.

Options for plugin 'continuations':

  -P:continuations:enable        Enable continuations