Why does stacktrace.log not fill with logback in grails 3?

Question

When you create a new grails application, the default logback.groovy file (and almost every example of a logback.groovy, even Mr Haki's example) contains the following code, which I have simplified to focus on the relevant piece:

root(ERROR, ['STDOUT'])

appender("FULL_STACKTRACE", FileAppender) {
    file = "build/stacktrace.log"
    append = true
    encoder(PatternLayoutEncoder) {
        pattern = "%level %logger - %msg%n"
    }
}
logger("StackTrace", ERROR, ['FULL_STACKTRACE'], false )

However, following this approach does not result in errors being output to the stacktrace.log file.

@JeffScottBrown's answer contained the following Bootstrap.groovy file to test if the stacktrace was logging as expected:

class BootStrap {

    def init = { servletContext ->
        log.error 'this is a new error'
    }
    def destroy = {
    }
}

With that bootstrap file, running the grails application will not produce any output into build/stacktrace.log.

If you remove the StackTrace logger, and add FULL_STACKTRACE to the root logger:

root(ERROR, ['STDOUT', 'FULL_STACKTRACE']

you will get output into the stacktrace.log.

Alternatively, rename the StackTrace logger to grails.app.init.Bootstrap (thanks to @JeffScottBrown for this line):

logger 'grails.app.init.BootStrap', ERROR, ['FULL_STACKTRACE'], false

and you will get output into the stacktrace.log

This observation leads me to believe that the StackTrace logger doesn't do anything. I further am led to believe that any logger not named for a package doesn't work.

As a result of all this, my question is:

• Does logback work for non-package/class named loggers?
• If so, why does the StackTrace logger in the default logback.groovy not result in output to stacktrace.log?

EDIT:

• The main issue for me is that the StackTrace logger seems completely unnecessary, so why is it included in the default file?

Second Edit:

Another way to confirm this is to make only the StackTrace logger write to the STDOUT appender, and watch stacktraces disappear from the console when you throw an exception:

logger("StackTrace", ERROR, ['STDOUT','FULL_STACKTRACE'], false) root(ERROR, [])

Obeisance

This is with Grails 3.1.0.RC2. I will try to do a test with a later version at some point. – Obeisance

It works. Check the build directory of the grails project. – Sherly

@Sherly what works? Are you saying your logback.groovy has only one logger using the FULL_STACKTRACE appender, namely the StackTrace logger defined as: logger("StackTrace", ERROR, ['FULL_STACKTRACE'], false )? If you have any other logger using FULL_STACKTRACE, you are bypassing the line I believe to be useless. – Obeisance

Answer 1

As a result of all this, my question is:

• Does logback work for non-package/class named loggers?

Yes, logback works regardless of the logger name.

• If so, why does the StackTrace logger in the default logback.groovy not result in output to stacktrace.log?

It does. I cannot reproduce the scenario where it doesn't. If you can, please file an issue at https://github.com/grails/grails-core/issues and include a sample app and we will get it straightened out.

Sorry for the trouble and thank you for the feedback.

Dubious

Answer 2

I expect that you aren't configuring the appender to be used properly.

The following works:

import grails.util.BuildSettings
import grails.util.Environment

// See http://logback.qos.ch/manual/groovy.html for details on configuration
appender('STDOUT', ConsoleAppender) {
    encoder(PatternLayoutEncoder) {
        pattern = "%level %logger - %msg%n"
    }
}

root(ERROR, ['STDOUT'])

def targetDir = BuildSettings.TARGET_DIR
if (Environment.isDevelopmentMode() && targetDir) {
    appender("FULL_STACKTRACE", FileAppender) {
        file = "${targetDir}/stacktrace.log"
        append = true
        encoder(PatternLayoutEncoder) {
            pattern = "%level %logger - %msg%n"
        }
    }
    logger("StackTrace", ERROR, ['FULL_STACKTRACE'], false)
}

logger 'grails.app.init.BootStrap',
        ERROR, ['FULL_STACKTRACE'], false

In BootStrap.groovy...

class BootStrap {

    def init = { servletContext ->
        log.error 'this is a new error'
    }
    def destroy = {
    }
}

That error shows up in stacktrace.log.

EDIT To Address New Questions:

Does logback work for non-package/class named loggers?

Yes.

If so, why does the StackTrace logger in the default logback.groovy not result in output to stacktrace.log?

The StackTrace logger does result in output being written to stacktrace.log for all of the loggers associated with the corresponding appender.

Dubious

This doesn't answer the question I had in mind, so I think I need to edit my question... My main issue is that the logger("StackTrace", ERROR... line appears in numerous places as an example, BUT it doesn't work. Your answer doesn't indicate that it works, it indicates that you need something in addition to it. Does that make sense? I'll edit my question to clarify. – Obeisance

I've edited the question to actually ask what I had in mind. – Obeisance

@RyanHeathcote "BUT it doesn't work" - It does work, as far as I can tell. If it isn't, create a sample app which demonstrates the issue and share a link to that. – Dubious

I can't tell if the confusion is related to misunderstanding log levels, appenders or if there really is a bug. A sample app which describes what you expect to work will clarify that. – Dubious

What confuses me is why the logger("StackTrace", ERROR... line is necessary at all. In my experimentation, without any other loggers using the FULL_STACKTRACE appender, it doesn't do anything, and I can get output into the stacktrace.log file without it. – Obeisance

When you say "The StackTrace logger does result in output being written to stacktrace.log for all of the loggers associated with the corresponding appender." -- My experiments would contradict this: it doesn't result in output being written for the loggers associated with the appender because I can use other loggers with that appender without the StackTrace logger existing. – Obeisance

I created a clean application, and the only changes I made were to the Bootstrap.groovy file, adding the line in your answer, and then in modified my logback.groovy according to the 3 versions in this gist: gist.github.com/slackboxster/8ed07fa21bdb5355bf04752e10f4b73e If I have a bit more time tomorrow I can create actual zip files of each difference. – Obeisance

Whatever isn't working as designed isn't clear to me. If whatever it is appears to be a Grails issue, feel free to file an issue at github.com/grails/grails-core/issues. – Dubious

Answer 3

change

logger("StackTrace", ERROR, ['FULL_STACKTRACE'], false )

to

logger("grails.app", INFO, ['FULL_STACKTRACE'], false)

will write all the logs in grails-app to stacktrace.log

Comprehension

Answer 4

Your log statement in Bootstrap.groovy:

log.error 'this is a new error'

logs a regular ERROR level message to the logger named grails.app.init.yourapp.BootStrap. It does not log to the logger named StackTrace. The FULL_STACKTRACE appender is for unfiltered stacktraces. These are written by the framework to the logger StackTrace.

If you replace

log.error 'this is a new error'

with

throw new RuntimeException("foo")

you will see the full stacktrace being logged to stacktrace.log

Biggerstaff

I tried this, based on what I'm seeing, the exception only causes a stacktrace to dump to stacktrace.log when the root logger appends to the FULL_STACKTRACE appender. I'm still not seeing stacktraces or anything routed specifically through the StackTrace logger. When I try to route StackTrace exclusively through STDOUT, I get no output. e.g. logger("StackTrace", ERROR, ['STDOUT','FULL_STACKTRACE'], false) root(ERROR, []) – Obeisance