Grails Log4J Not Logging In Production

1
votes

I have a Grails 1.3.7 application and am trying to setup log4j for production in the configuration. The log4j settings were fine in development, but I can't get anything to show for production. I am trying to make a rolling file among other things, but I can't get anything to show. I even have the configuration at the "info" level so that I can ensure something will come through. I don't see anything of interest in the tomcat logs on the server. Any ideas?

log4j = {
    def catalinaBase = System.properties.getProperty('catalina.base')
    if (!catalinaBase) catalinaBase = '.'   // just in case
    def logDirectory = "${catalinaBase}/logs"

    root { info "stdout", "roll", "errors" }

    // Log all at the error level
    info 'org.apache.',
    'org.tomcat.',
    'grails.app',
    'org.acegisecurity',
    'org.codehaus.groovy.grails.web.servlet', // controllers
    'org.codehaus.groovy.grails.web.pages', // GSP
    'org.codehaus.groovy.grails.web.sitemesh', // layouts
    'org.codehaus.groovy.grails.web.mapping.filter', // URL mapping
    'org.codehaus.groovy.grails.web.mapping', // URL mapping
    'org.codehaus.groovy.grails.commons', // core / classloading
    'org.codehaus.groovy.grails.plugins', // plugins
    'org.codehaus.groovy.grails.orm.hibernate', // hibernate integration
    'org.springframework',
    'org.hibernate'
    warn 'org.mortbay.log'
    warn 'grails.app'

    appenders {
        console name: "stdout", layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n")
        file name: "errors", file: "pps-errors.log", layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n")
        appender new org.apache.log4j.DailyRollingFileAppender(name:"roll", datePattern: "'.'yyyy-MM-dd", file:"pps-rolling.log", layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n"))

        environments {
            production {
                file name: "prod-errors", file: "${logDirectory}/pps-errors.log".toString(), layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n")
                appender new org.apache.log4j.DailyRollingFileAppender(name:"prod-roll", datePattern: "'.'yyyy-MM-dd", file:"${logDirectory}/pps-errors-daily.log".toString(), layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n"))
            }
        }
    }

    environments {
        development{

            debug stdout:   'org.hibernate.SQL',
            'org.hibernate.transaction'//,
            //'org.hibernate.cache'
            //trace stdout: 'org.hibernate.type'
        }
        test {
            root { error "stdout", "roll", "errors" }
        }
        production {

            root {
                info "prod-roll", "prod-errors", "stdout", "roll", "errors"
            }

            info 'org.apache.',
            'org.tomcat.',
            'grails.app',
            'org.acegisecurity',
            'org.codehaus.groovy.grails.web.servlet', // controllers
            'org.codehaus.groovy.grails.web.pages', // GSP
            'org.codehaus.groovy.grails.web.sitemesh', // layouts
            'org.codehaus.groovy.grails.web.mapping.filter', // URL mapping
            'org.codehaus.groovy.grails.web.mapping', // URL mapping
            'org.codehaus.groovy.grails.commons', // core / classloading
            'org.codehaus.groovy.grails.plugins', // plugins
            'org.codehaus.groovy.grails.orm.hibernate', // hibernate integration
            'org.springframework',
            'org.hibernate'
        }
    }

    debug 'grails.app.task'
    //grails = "debug"
    //StackTrace = "error,errors"

    //additivity.StackTrace = false
}

EDIT:

The catalina.out file in tomcat6 has the following:

log4j:WARN No appenders could be found for logger (org.springframework.web.context.ContextLoader). log4j:WARN Please initialize the log4j system properly.

SECOND EDIT:

I made a minimal configuration following Burt below to this:

log4j = {
    String logDirectory = "${System.getProperty('catalina.base') ?: '.'}/logs"

    info 'org.apache.',
            'org.tomcat.',
            'grails.app',
            'org.acegisecurity',
            'org.codehaus.groovy.grails',
            'org.springframework',
            'org.hibernate'
    warn 'grails.app'

    appenders {
        file name: "errors", file: "${logDirectory}/pps-errors.log",
                layout: pattern(conversionPattern: commonPattern)
        appender new DailyRollingFileAppender(
                name:"roll", datePattern: "'.'yyyy-MM-dd",
                file:"${logDirectory}/pps-rolling.log",
                layout: pattern(conversionPattern: commonPattern))

        file name: "prod-errors", file: "${logDirectory}/pps-errors.log",
                layout: pattern(conversionPattern: commonPattern)
        appender new DailyRollingFileAppender(
                name:"prod-roll", datePattern: "'.'yyyy-MM-dd",
                file:"${logDirectory}/pps-errors-daily.log",
                layout: pattern(conversionPattern: commonPattern))
    }

    root {
        info "prod-roll", "prod-errors", "roll", "errors"
    }
}

I still get the same message in tomcat and still no logging takes place. Is there something I have to do to setup tomcat for logging in this manner?

EDIT 3: Output from App-Info. This does not have my custom appenders in it, leading me to believe that that is the problem. However, when I run the app in development mode, I can verify that the log files are in fact created:

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">    <appender name="stacktraceLog" class="org.apache.log4j.FileAppender">
      <param name="file" value="/home/devon/Documents/SynaSync/Projects/ProjectPointSpread/Source/trunk/target/stacktrace.log"/>
      <param name="name" value="stacktraceLog"/>
      <layout class="org.apache.log4j.PatternLayout">
         <param name="conversionPattern" value="%d [%t] %-5p %c{2} %x
- %m%n"/>
      </layout>    </appender>    <appender name="stdout" class="org.apache.log4j.ConsoleAppender">
      <param name="name" value="stdout"/>
      <layout class="org.apache.log4j.PatternLayout">
         <param name="conversionPattern" value="%d [%t] %-5p %c{2} %x
- %m%n"/>
      </layout>    </appender>    <logger name="StackTrace" additivity="false">
      <appender-ref ref="stacktraceLog"/>    </logger>    <logger name="grails.app">
      <level value="WARN"/>    </logger>    <logger name="grails.app.task">
      <level value="DEBUG"/>    </logger>    <logger name="org.acegisecurity">
      <level value="INFO"/>    </logger>    <logger name="org.apache.">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.commons">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.orm.hibernate">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.plugins">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.web.mapping">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.web.mapping.filter">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.web.pages">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.web.servlet">
      <level value="INFO"/>    </logger>    <logger name="org.codehaus.groovy.grails.web.sitemesh">
      <level value="INFO"/>    </logger>    <logger name="org.hibernate">
      <level value="INFO"/>    </logger>    <logger name="org.springframework">
      <level value="INFO"/>    </logger>    <logger name="org.tomcat.">
      <level value="INFO"/>    </logger>    <root>
      <level value="INFO"/>
      <appender-ref ref="stdout"/>    </root> </log4j:configuration>

EDIT 4: I am still having a problem logging in production. Now, when I use the below logging config and run it in debug mode, I can correctly see all of the appenders in the app-info tool. However, when I build the code for production the app-info reveals that the log4j.xml that would be generated is pretty much blank:

New config:

log4j = {
    String logDirectory = "${System.getProperty('catalina.base') ?: '.'}/logs"

    // For some reason the 'appenders' section had to come first and it messed everything up! Maybe it just 
    // needs to go before root
    appenders {
        console name: "stdout", layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n")
        file name: "errors", file: "pps-errors.log", layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n")
        appender new org.apache.log4j.DailyRollingFileAppender(name:"roll", datePattern: "'.'yyyy-MM-dd", file:"pps-rolling.log", layout: pattern(conversionPattern: "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n"))

    }


    root { info "stdout", "roll", "errors" }
    // Log all at the error level
    info 'org.apache.',
    'org.tomcat.',
    'grails.app',
    'org.acegisecurity',
    'org.codehaus.groovy.grails.web.servlet', // controllers
    'org.codehaus.groovy.grails.web.pages', // GSP
    'org.codehaus.groovy.grails.web.sitemesh', // layouts
    'org.codehaus.groovy.grails.web.mapping.filter', // URL mapping
    'org.codehaus.groovy.grails.web.mapping', // URL mapping
    'org.codehaus.groovy.grails.commons', // core / classloading
    'org.codehaus.groovy.grails.plugins', // plugins
    'org.codehaus.groovy.grails.orm.hibernate', // hibernate integration
    'org.springframework',
    'org.hibernate'
    warn 'grails.app'
}

Output log4j.xml in Prod:

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">
   <logger name="Test">
      <level value="ALL"/>
   </logger>
   <root>
      <level value="DEBUG"/>
   </root>
</log4j:configuration>
1
grailslog4jtomcat6
How do you run your app? Tomcat and deploy the grails application as war? Or are you using a different servlet engine? – Stefan Armbruster
@Stefan Armbruster - I do a grails prod war, then I put it in the tomcat webapps folder and restart tomcat. Also, I am editing above to add extra information. Thanks. – skaz

1 Answers

6
votes

Unfortunately you can't add environments blocks in arbitrary locations, and in general the log4j configuration can't be made very DRY since it has to occur in one closure. Here's what I think you were getting at:

import org.apache.log4j.DailyRollingFileAppender

String commonPattern = "%d{yyyy-MMM-dd HH:mm:ss,SSS} [%t] %c %x%n %-5p %m%n"
environments {
   development {
      log4j = {
         info 'org.apache.',
              'org.tomcat.',
              'org.acegisecurity',
              'org.codehaus.groovy.grails',
              'org.springframework',
              'org.hibernate'
         warn 'grails.app'
         debug 'org.hibernate.SQL',
               'org.hibernate.transaction'
      }
   }
   test {
      log4j = {
         root {
            error "stdout"
         }

         info 'org.apache.',
              'org.tomcat.',
              'org.acegisecurity',
              'org.codehaus.groovy.grails',
              'org.springframework',
              'org.hibernate'
         warn 'grails.app'
      }
   }
   production {

      log4j = {
         String logDirectory = "${System.getProperty('catalina.base') ?: '.'}/logs"

         info 'org.apache.',
              'org.tomcat.',
              'grails.app',
              'org.acegisecurity',
              'org.codehaus.groovy.grails',
              'org.springframework',
              'org.hibernate'
         warn 'grails.app'

         appenders {
            file name: "errors", file: "${logDirectory}/pps-errors.log",
                 layout: pattern(conversionPattern: commonPattern)
            appender new DailyRollingFileAppender(
               name:"roll", datePattern: "'.'yyyy-MM-dd",
               file:"${logDirectory}/pps-rolling.log",
               layout: pattern(conversionPattern: commonPattern))

            file name: "prod-errors", file: "${logDirectory}/pps-errors.log",
                 layout: pattern(conversionPattern: commonPattern)
            appender new DailyRollingFileAppender(
               name:"prod-roll", datePattern: "'.'yyyy-MM-dd",
               file:"${logDirectory}/pps-errors-daily.log",
               layout: pattern(conversionPattern: commonPattern))
         }

         root {
            info "prod-roll", "prod-errors", "roll", "errors"
         }
      }
   }
}

I removed 'org.mortbay.log' since I doubt you're using Jetty - put it back if you are. Also 'grails.app' is listed under info and warn. And I removed the "stdout" appender from prod since that will dump to catalina.out and you've already configured file loggers.

The app-info plugin has a feature where it will reverse-engineer the XML that could have been used to configure the equivalent logging configuration, if you were using the traditional log4j.xml approach. It's not exact but should be very close. I find it's very useful for debugging logging issues like this since even if you haven't used the XML file syntax you can compare the Config.groovy settings with what ends up in the XML and see what's missing, misconfigured, etc.