Grails How to change logging level in runtime | Grails Set Log Level for Grails

Grails How to change logging level in runtime | Grails Set Log Level for Grails

Need to create a util class at first as below:

package com.log4j

import grails.util.Holders
import org.apache.log4j.Category
import org.apache.log4j.Level
import org.apache.log4j.Logger

/**
 * Created by pritom on 17/10/2017.
 */
class UtilsBase {
    protected static Logger log

    static void setLogLevel() {
        Level level = Holders.config?.myconfig?.log4j?.logLevel ?: Level.ERROR
        println("SETTING-LOG-LEVEL=${level}")
        Enumeration allLoggers = log.getLoggerRepository().getCurrentCategories()
        log.setLevel(level)
        while (allLoggers.hasMoreElements()) {
            Category category = (Category) allLoggers.nextElement()
            category.setLevel(level)
        }
    }

    static {
        println("Log-enabled-for-${this.class.simpleName}")
        log = Logger.getLogger(this.class)
    }
}

Need to do something in Config.groovy as below:

myconfig {
    log4j {
        /* Here you can define your LOG level */
        logLevel = Level.INFO
    }
}

// log4j configuration
// log4j configuration
log4j.main = {
    def pattern = new PatternLayout("%d{yyyy-MM-dd//HH:mm:ss.SSS} [%t] %x %-5p %c{2} - %m%n")

    appenders {
        console name: "stdout", layout: pattern
    }

    error   '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',
            'net.sf.ehcache.hibernate',
            'com.log4j'

    debug   'com.log4j'

    warn    'org.springframework',
            'org.hibernate',
            'grails.plugins.springsecurity',
            'groovyx.net.http',
            'com.log4j'

    all     'grails.app'
}

Now you have to set log level fro BootStrap.goovy as below

import com.log4j.UtilsBase

class BootStrap {

    def init = { servletContext ->
        UtilsBase.setLogLevel()
    }
    def destroy = {

    }
}

And finally start loggin

package com.log4j

class Log4jController extends UtilsBase {
    def index() {
        log.info("Info")
        log.warn("Warn")
        log.error("Error")
        render ""
    }
}

Will output as below:

2017-10-17//16:16:15.512 [http-bio-8808-exec-4]  INFO  log4j.Log4jController - Info
2017-10-17//16:16:15.515 [http-bio-8808-exec-4]  WARN  log4j.Log4jController - Warn
2017-10-17//16:16:15.515 [http-bio-8808-exec-4]  ERROR log4j.Log4jController - Error

You can download full source code from here

Display Hibernate Sql Parameter Values

Configure Log4j in Hibernate

Create a file named 'log4j.properties' under main project, where 'hibernate.cfg.xml' exists with following contents. This configuration will log sql in a file, the location you specified and also log in your project IDE console.

# Log everything. Good for troubleshooting  
log4j.logger.org.hibernate=INFO
# Log all SQL DML statements as they are executed
log4j.logger.org.hibernate.SQL=TRACE
# Log all JDBC parameters(TRACE|INHERITED);
log4j.logger.org.hibernate.type=TRACE
log4j.logger.org.hibernate.hql.ast.AST=info
# Log all SQL DDL statements as they are executed(INHERITED|WARN)
log4j.logger.org.hibernate.tool.hbm2ddl=INHERITED
log4j.logger.org.hibernate.hql=debug
log4j.logger.org.hibernate.cache=info
log4j.logger.org.hibernate.jdbc=debug   
# Log all second-level cache activity
log4j.logger.org.hibernate.cache=INHERITED
# Log all OSCache activity - used by Hibernate
log4j.logger.com.opensymphony.oscache=INHERITED
# Log transaction related activity
log4j.logger.org.hibernate.transaction=INHERITED
# Log all JDBC resource acquisition
log4j.logger.org.hibernate.jdbc=INHERITED
# Log all JAAS authorization requests
log4j.logger.org.hibernate.secure=INHERITED
# Root logger option  
log4j.rootLogger=INFO, CUSTOM_FILE, CUSTOM_STD_OUT  

# Define the file appender
log4j.appender.CUSTOM_FILE=org.apache.log4j.DailyRollingFileAppender
# Set the DatePattern (Every hour interval)
log4j.appender.CUSTOM_FILE.DatePattern='['yyyy-MM-dd-HH'].log'
# Set the DatePattern (Every minute interval)
#log4j.appender.CUSTOM_FILE.DatePattern='['yyyy-MM-dd-HH-mm'].log'
# Set the append to false, should not overwrite
log4j.appender.CUSTOM_FILE.Append=true
# Set the name of the file.
# It'll be created every hour/minute with different 
# filename(appnded with yyyy-MM-dd-HH/yyyy-MM-dd-HH-mm).
log4j.appender.CUSTOM_FILE.File=C:/tmp/debug.log
# Define the layout for file appender
log4j.appender.CUSTOM_FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.CUSTOM_FILE.layout.conversionPattern= %d{HH:mm:ss} %m%n

# Direct log messages to stdout  
log4j.appender.CUSTOM_STD_OUT=org.apache.log4j.ConsoleAppender  
log4j.appender.CUSTOM_STD_OUT.Target=System.out  
log4j.appender.CUSTOM_STD_OUT.layout=org.apache.log4j.PatternLayout  
log4j.appender.CUSTOM_STD_OUT.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n 
log4j.appender.CUSTOM_STD_OUT.layout.ConversionPattern=%d{ABSOLUTE} - %m%n

Execute following line of code when project start/run, before performing any CRUD operations:

ClassLoader loader = Thread.currentThread().getContextClassLoader();
URL url = loader.getResource("log4j.properties");
System.out.println(url);
PropertyConfigurator.configure(url);

You have to include log4j-1.2.16.jar in your project

When you perform query, output would be like this in your IDE consle:

/* When perform HQL */
10:30:29,149 - HQL: SELECT MIN(id) FROM com.pkm.domains.User

/* When perform SQL */
10:30:29,149 - SQL: select min(user0_.id) as col_0_0_ from User user0_
10:30:29,149 - throwQueryException() : no errors
10:30:29,191 - select min(user0_.id) as col_0_0_ from User user0_ limit ?
10:30:29,226 - Found [14] as column [col_0_0_]
10:30:29,228 - select user0_.id as id0_0_, user0_.date_updated as date2_0_0_, user0_.email as email0_0_, user0_.first_name as first4_0_0_, user0_.last_name as last5_0_0_, user0_.phone_number as phone6_0_0_, user0_.area_code as area7_0_0_ from User user0_ where user0_.id=?
10:30:29,230 - binding parameter [1] as [BIGINT] - 14
10:30:29,238 - Found [2014-05-10 10:23:08.0] as column [date2_0_0_]
10:30:29,238 - Found [pritomkucse@gmail.com] as column [email0_0_]
10:30:29,238 - Found [Pritom] as column [first4_0_0_]
10:30:29,239 - Found [Kumar Mondal] as column [last5_0_0_]

/* Update Query */
10:30:29,261 - update User set date_updated=?, email=?, first_name=?, last_name=?, phone_number=?, area_code=? where id=?
10:30:29,262 - binding parameter [1] as [TIMESTAMP] - Sat May 10 10:30:29 ALMT 2014
10:30:29,263 - binding parameter [2] as [VARCHAR] - pritomkucse@gmail.com
10:30:29,263 - binding parameter [3] as [VARCHAR] - Pritom
10:30:29,264 - binding parameter [4] as [VARCHAR] - Kumar Mondal
10:30:29,264 - binding parameter [7] as [BIGINT] - 14

Download complete example. This example also contains hibernate interceptor logic

Logging Hibernate SQL in Grails With Parameters

Add the following line to DataSource.groovy marked yellow

dataSource {
    pooled = true
    url = jdbc:mysql://localhost/database_name?useUnicode=yes&characterEncoding=UTF-8
    driverClassName = com.mysql.jdbc.Driver
    username = database_user_name
    password = database_password
    dialect = org.hibernate.dialect.MySQL5InnoDBDialect
    dbCreate = "update"
    logSql = true
    properties {
        maxActive = 1000
        maxIdle = 100
        minIdle = 50
        initialSize = 1
        minEvictableIdleTimeMillis = 60000
        timeBetweenEvictionRunsMillis = 60000
        numTestsPerEvictionRun = 3
        maxWait = 10000
        testOnBorrow = true
        testWhileIdle = true
        testOnReturn = true
        validationQuery = "SELECT 1"
    }
}

Add the following two code block to last of the file

log4j = {
    debug 'org.hibernate.SQL'
    trace 'org.hibernate.type.descriptor.sql.BasicBinder'
}

hibernate {
    cache.use_second_level_cache = true
    cache.use_query_cache = true
    cache.region.factory_class = 'net.sf.ehcache.hibernate.EhCacheRegionFactory'
    cache.provider_class = 'net.sf.ehcache.hibernate.EhCacheProvider'
    format_sql = false
    use_sql_comments = true
}

Example output of trace/debug

Hibernate: /* insert com.pkm.LogTest */ insert into log_test (created, name, display_name, a_long_value) values (?, ?, ?, ?)
2014-05-05 09:42:44,803 [http-bio-8011-exec-10] TRACE sql.BasicBinder  - binding parameter [1] as [TIMESTAMP] - Mon May 05 09:42:44 ALMT 2014
2014-05-05 09:42:44,803 [http-bio-8011-exec-10] TRACE sql.BasicBinder  - binding parameter [2] as [VARCHAR] - Pritom Kumar Mondal
2014-05-05 09:42:44,803 [http-bio-8011-exec-10] TRACE sql.BasicBinder  - binding parameter [3] as [VARCHAR] - pritom
2014-05-05 09:42:44,803 [http-bio-8011-exec-10] TRACE sql.BasicBinder  - binding parameter [4] as [BIGINT] - 3