Use XMLs not groovy scripts with db migration plugin!

I have 48 domain classes in my Grails 2.1 project and I use Grails Database Migration Plugin 1.2 for a database management. Recently I’ve noticed that it becomes terribly slow when running application, even if there are no changes to be applied. I swit…

I have 48 domain classes in my Grails 2.1 project and I use Grails Database Migration Plugin 1.2 for a database management. Recently I’ve noticed that it becomes terribly slow when running application, even if there are no changes to be applied.

I switched do debug logging level for liquibase package and I found that it takes about 15 seconds to parse changelog.groovy and 20 files that were included in it!

Prepare benchmark

I couldn’t belive it so I’ve created two new clean changelogs:

$ grails dbm-generate-changelog changelog.groovy
$ grails dbm-generate-changelog changelog.xml

Both of these changelogs contain 229 change sets. It is enough that you can benchmark parsers for them. Two parsers in question are:

  • grails.plugin.databasemigration.GrailsChangeLogParser
  • liquibase.parser.core.xml.XMLChangeLogSAXParser

I need to modify a line in my Config.groovy and switch changelog.groovy with changelog.xml for a second test:

grails.plugin.databasemigration.updateOnStart = true
grails.plugin.databasemigration.updateOnStartFileNames = ["changelog.groovy"]
// grails.plugin.databasemigration.updateOnStartFileNames = ["changelog.xml"] grails.plugin.databasemigration.updateOnStart = true
grails.plugin.databasemigration.updateOnStartFileNames = ["changelog-all.groovy"]
// grails.plugin.databasemigration.updateOnStartFileNames = ["changelog-all.xml"]

Profile with JProfiler

I want to profile execution time. I use JProfiler from ej-technologies to measure execution times. Please notice that I don’t want to benchmark SQL queries performed by liquibase. I am only focused on parse method of these two classes.

Here’s how I set up JProfiler:

I switch to CPU Views – Method statistics and I click “Record”. Here are results for both parsers:

Results for changelog.groovy

Results for changelog.xml

Analysis

My assumptions were correct: 8 339 ms vs 139 ms. Parsing XML is 60 times faster! I want to jump and sing: “I switch to XML now!”, but I have some concerns. I have a production database that I need to be compatible with. And I should rewrite my all groovy changelog files by hand. So it’s not so trivial and it’s a time consuming and error prone task.

So as much as I want to switch to XML now, I won’t. But if you start your adventure with database migration plugin today I have an advice for you: use XML if you start from scratch.

For now I’ve just submitted a new JIRA issue – GrailsChangeLogParser – parse method is very slow and I hope it can be greatly improved.

You May Also Like

Agile Skills Project at my company

Unfulfilled programmers Erich Fromm, a famous humanist, philosopher and psychologist strongly believed that people are basically good. If he was right, then either our society is a mind-breaking dystopia or we have a great misfortune of working i... Unfulfilled programmers Erich Fromm, a famous humanist, philosopher and psychologist strongly believed that people are basically good. If he was right, then either our society is a mind-breaking dystopia or we have a great misfortune of working i...

GWT Designer for Eclipse 3.6 can cause project compile freeze

Lately I installed GWT Designer for Eclipse Helios (3.6). I wanted to check it's features. They aren't so cool I've expected but that's other story. The problem was that suddenly my main GWT enabled project began to freeze during compilation.  The...Lately I installed GWT Designer for Eclipse Helios (3.6). I wanted to check it's features. They aren't so cool I've expected but that's other story. The problem was that suddenly my main GWT enabled project began to freeze during compilation.  The...

Inconsistent Dependency Injection to domains with Grails

I've encountered strange behavior with a domain class in my project: services that should be injected were null. I've became suspicious as why is that? Services are injected properly in other domain classes so why this one is different?

Constructors experiment

I've created an experiment. I've created empty LibraryService that should be injected and Book domain class like this:

class Book {
def libraryService

String author
String title
int pageCount

Book() {
println("Finished constructor Book()")
}

Book(String author) {
this()
this.@author = author
println("Finished constructor Book(String author)")
}

Book(String author, String title) {
super()
this.@author = author
this.@title = title
println("Finished constructor Book(String author, String title)")
}

Book(String author, String title, int pageCount) {
this.@author = author
this.@title = title
this.@pageCount = pageCount
println("Finished constructor Book(String author, String title, int pageCount)")
}

void logInjectedService() {
println(" Service libraryService is injected? -> $libraryService")
}
}
class LibraryService {
def serviceMethod() {
}
}

Book has 4 explicit constructors. I want to check which constructor is injecting dependecies. This is my method that constructs Book objects and I called it in controller:

class BookController {
def index() {
constructAndExamineBooks()
}

static constructAndExamineBooks() {
println("Started constructAndExamineBooks")
Book book1 = new Book().logInjectedService()
Book book2 = new Book("foo").logInjectedService()
Book book3 = new Book("foo", 'bar').logInjectedService()
Book book4 = new Book("foo", 'bar', 100).logInjectedService()
Book book5 = new Book(author: "foo", title: 'bar')
println("Finished constructor Book(Map params)")
book5.logInjectedService()
}
}

Analysis

Output looks like this:

Started constructAndExamineBooks
Finished constructor Book()
Service libraryService is injected? -> eu.spoonman.refaktor.LibraryService@2affcce2
Finished constructor Book()
Finished constructor Book(String author)
Service libraryService is injected? -> eu.spoonman.refaktor.LibraryService@2affcce2
Finished constructor Book(String author, String title)
Service libraryService is injected? -> null
Finished constructor Book(String author, String title, int pageCount)
Service libraryService is injected? -> null
Finished constructor Book()
Finished constructor Book(Map params)
Service libraryService is injected? -> eu.spoonman.refaktor.LibraryService@2affcce2

What do we see?

  1. Empty constructor injects dependencies.
  2. Constructor that invokes empty constructor explicitly injects dependencies.
  3. Constructor that invokes parent's constructor explicitly does not inject dependencies.
  4. Constructor without any explicit call declared does not call empty constructor thus it does not inject dependencies.
  5. Constructor provied by Grails with a map as a parameter invokes empty constructor and injects dependencies.

Conclusion

Always explicitily invoke empty constructor in your Grail domain classes to ensure Dependency Injection! I didn't know until today either!