Search code examples
hibernategrailslog4j

Logging Hibernate SELECT statements into their own log files


We will have a full UAT for the next two weeks before our Grails 2.4.4 application goes live. I want to log all SELECT statements generated by Hibernate4 that will be executed by then so I could develop properly optimized database indexes. Is there a configuration in Grails or Tomcat that will log SELECT statements into a .log file distributed per day similar to catalina.YYYY-MM-dd.log? I have configured log4j to log the queries through Config.groovy:

log4j.main = {
    ...
    debug 'org.hibernate.SQL', 'org.codehaus.groovy.grails.orm.hibernate.cfg'
    ...
}

It logs it on catalina.out. Can I configure it so that it will append it to a different log file, let's say hibernate.YYYY-MM-dd.log? I do not mind if the parameter will be replaced by ?, it is fine as long as I can get the SELECT statement


Solution

  • I cannot configure it to create separate files for hibernate.SQL logs through @Daniel's answer. But since my team needs to record the queries starting tomorrow, I decided just manually extract the required logs from catalina.out instead.

    First, enable logging of SQL statements of your Grails Application before creating a war

    log4j.main = {
        ...
        debug 'org.hibernate.SQL'
        ...
    }
    

    The application will log all SQL statements into catalina.out, which by the way, will cause the file to become unnecessarily large. Now we need to schedule a cron task every start of the day to extract the statements from the previous day and compile them into a separate daily file.

    cat catalina.out | grep "$(date -d "yesterday 13:00" '+%Y-%m-%d').*DEBUG hibernate.SQL" | cut -d " " -f 8- | sort | uniq | sed 's/$/;\n/' > "hibernate.$(date -d "yesterday 13:00" '+%Y-%m-%d').log"
    

    The beakdown of the bash script is as follow:

    1. cat catalina.out Fetch the source file.
    2. grep "$(date -d "yesterday 13:00" '+%Y-%m-%d').*DEBUG hibernate.SQL" Filter only lines that start with the date yesterday (that you get through this part: $(date -d "yesterday 13:00" '+%Y-%m-%d')) and that has the string DEBUG hibernate.SQL somewhere in between the string.
    3. cut -d " " -f 8- Remove the first part of the line YYYY-MM-dd HH:mm:ss,xxx [http-bio-xxx.xxx.xxx.xxx-xx-exec-x] DEBUG hibernate.SQL -. Our line should immediately start with SELECT, UPDATE, or DELETE.
    4. sort Sorts the line, alphabetically (optional).
    5. uniq Remove duplicate lines (optional).
    6. sed 's/$/;\n/' append a semicolon and a new line at the end of each line.
    7. > "hibernate.$(date -d "yesterday 13:00" '+%Y-%m-%d').log" Save the output to a new file hibernate.YYYY-MM-dd.log.

    I prefer to not use this "hacky" solution if not for the urgency, we need a solution by tomorrow after all. If someone can still provide the proper way to configure this through log4j, Grails Config.groovy, or Tomcat, will really be appreciated.