Grails 2.1 から標準でインストールされているCache Pluginを試す

http://grails.org/plugin/cachegrails 2.1からデフォルトでインストールされています。実態としてはSpringのCache Abstractionを薄くラップしたような形です。Serviceのメソッドや、Controller、またはGSPのレンダリングをキャッシュできます。

メソッドに付与する使い方は非常にシンプルで、grails.plugin.cacheパッケージにある以下の3つのアノテーションを使用します。

  • @Cacheable
  • @CacheEvict
  • @CachePut

それぞれ個別に見ていきます。

@Cacheable

このアノテーションを付与するとメソッドの戻り値をキャッシュします。例えば以下のような形です。

class BookService {

    @Cacheable('books')
    Book get(id) {
        Book.get(id)
    }

}

@Cacheableにはvalue属性を設定しますが、これはキャッシュする情報に任意の名前を設定します。この名前毎にキャッシュ領域が作られることになります。

また、@Cacheableはkey属性を持ちます。これは省略可能で、省略した場合は自動的にメソッドの仮引数がkeyに設定されます。

上記の例の

    @Cacheable('books')
    Book get(id) {

    @Cacheable(value = 'books', key = '#id')
    Book get(id) {

と同じ意味になります。#idとしているようにkeyの指定はSpEL(Spring Expression Language)が使用できます。これを使用することで仮引数がオブジェクトの場合にプロパティをたぐっていき#obj.idといったような指定も可能です。詳しくはSpringのドキュメントを参照してください。

簡単なテストをGrailsのIntegrationTestで書いてみます。

class Book {
    String title
}
import grails.plugin.spock.IntegrationSpec

class BookServiceSpec extends IntegrationSpec {

    def bookService

    def grailsCacheManager

    def cleanup() {
        grailsCacheManager.destroyCache('books')
    }

    def "キャッシュ追加の動作確認"() {
        given:
        def book = new Book(title: 'dummyTitle').save(flush: true)
        book.discard() // hibernateの1次キャッシュから取得しないようdiscard()する。

        and: "キャッシュには何も保存されていない"
        assert booksCache.size() == 0

        when:
        def cachedBook = bookService.get(book.id)

        then:
        cachedBook.title == 'dummyTitle'

        and: "キャッシュ取得したオブジェクトがキャッシュされているはず"
        booksCache == [(book.id): cachedBook]

        when: "直接永続化されている情報を変更する"
        cachedBook.discard() // book.save()した際にbookがhibernateの1キャッシュに乗るで二重ロードにならないようcachedBookはdiscard()する。
        book.title = 'newTitle'
        book.save(flush: true)

        then: "キャッシュには影響がない"
        booksCache[book.id].title == 'dummyTitle'

        when: "メソッドを経由してちゃんとキャッシュした情報が取得されるか確認"
        cachedBook = bookService.get(book.id)

        then: "キャッシュの値は変更されていない"
        cachedBook.title == 'dummyTitle'
    }

    private getBooksCache() {
        grailsCacheManager.getCache('books').getNativeCache()
    }

}

まずは

class BookServiceSpec extends IntegrationSpec {
    ...
    def grailsCacheManager
    ...
    private getBooksCache() {
        grailsCacheManager.getCache('books').getNativeCache()
    }

}

について。これはSpringのCacheManagerインタフェースを継承したGrialsCacheManagerインタフェースの実装がSpringBeanとして登録されます。Cache Pluginは cache-ehcache、cache-redisといったプラグインと併用することで拡張可能ですが、とく指定しなければデフォルトではGrailsConcurrentMapCacheManagerが使われます。名前の通りConcurrentHashMapを使用した単純な実装です。

上記のコードはgrailsCacheManagerにGrailsConcurrentMapCacheManagerのインスタンスがイジェクトされ、grailsCacheManager.getCache('books').getNativeCache()でbooksをキャッシュしているConcurrentHashMapのインスタンスを取得できます。getNativeCache()の戻り値はObjectで定義されており、GrailsConcurrentMapCacheManagerの場合、ConcurrentHashMapのインスタンスになるだけで、他の実装を使用する場合はきっと違う何かがとれるでしょう(よくわからない)。

テストコードの方ではbookService.getを初めて呼び出したタイミングで、その取得されたオブジェクトがキャッシュされます。以後、何度 bookService.getを呼び出しても、@CacheEvict使ってキャッシュをクリアするか、@CachePutを使ってキャッシュを更新するまで、そのキャッシュの値が使用されます(cache-ehcache、cache-redisといった連携プラグインで独自のクリアの仕組みがある可能性はある)。

@CacheEvict

@CacheEvictはキャッシュをクリアする仕組みです。以下のように使います。

class BookService {
    ...
 
    @CacheEvict('books')
    void clear(id) {
    }

    @CacheEvict(value = 'books', allEntries = true)
    void clearAll() {
    }

}

一つ目のメソッドclear(id)を呼び出すと'books'キャッシュのkeyがidのキャッシュをクリアします。keyの指定は先程と一緒で、上記は以下のように定義しているのと同じです。

    @CacheEvict(value = 'books', key = '#id')
    void clear(id) {
    }

2つ目のメソッドでは@CacheEvictの属性にallEntries = trueを指定しています。これを指定すと特定のkeyのキャッシュ削除ではなく、そのキャッシュすべてを削除します。上記では'books'のキャッシュすべてが削除されます。

テストを書いてみます。

    def "キャッシュ削除の動作確認"() {
        given:
        def book1 = new Book(title: 'title1').save(flush: true)
        def book2 = new Book(title: 'title2').save(flush: true)

        and: "キャッシュには何も保存されていない"
        assert booksCache == [:]

        when: "値を一度取得してキャッシュさせる"
        bookService.get(book1.id)
        bookService.get(book2.id)

        then: "キャッシュにbook1、book2が入っているはず"
        booksCache == [(book1.id): book1, (book2.id): book2]

        when: "book1をキャッシュから削除"
        bookService.clear(book1.id)

        then: "キャッシュからbook1が削除されている"
        booksCache == [(book2.id): book2]
    }

    def "キャッシュ全削除の動作確認"() {
        given:
        def book1 = new Book(title: 'title1').save(flush: true)
        def book2 = new Book(title: 'title2').save(flush: true)

        and: "キャッシュには何も保存されていない"
        assert booksCache == [:]

        when: "値を一度取得してキャッシュさせる"
        bookService.get(book1.id)
        bookService.get(book2.id)

        then: "キャッシュにbook1、book2が入っているはず"
        booksCache == [(book1.id): book1, (book2.id): book2]

        when: "キャッシュを全削除"
        bookService.clearAll()

        then: "キャッシュすべて削除されている"
        booksCache == [:]
    }

@CachePut

最後は@CachePutで、これは@CacheEvictと、@Cacheable組み合わせたような動作で、指定されたkeyに対するキャッシュをクリアし、keyに対して戻り値をキャッシュします。以下のように使用します。

class BookService {
    ....

    @CachePut(value = 'books', key = '#book.id')
    Book put(book) {
        book
    }

}

テストを書いてみます。

    def "キャッシュ更新の動作確認"() {
        given:
        def book = new Book(title: 'dummyTitle').save(flush: true)

        and: "キャッシュには何も保存されていない"
        assert booksCache == [:]

        when:
        def cachedBook = bookService.get(book.id)

        then: "キャッシュ取得したオブジェクトがキャッシュされているはず"
        booksCache == [(book.id): book]
        booksCache[book.id].title == 'dummyTitle'

        when: "キャッシュの値を更新する"
        cachedBook.title = 'updatedTitle'
        bookService.put(cachedBook)

        then: "キャッシュの値が更新されているはず"
        booksCache[book.id].title == 'updatedTitle'
    }

ちなみに対象のkeyのキャッシュが存在しない場合は、単に新たにキャッシュされるだけです。

    def "現在キャッシュされていない状態でのキャッシュ更新"() {
        given:
        def book = new Book(title: 'dummyTitle').save(flush: true)

        and: "キャッシュには何も保存されていない"
        assert booksCache == [:]

        when: "キャッシュがない状態でPUTする"
        bookService.put(book)

        then: "キャッシュされている"
        booksCache == [(book.id): book]
    }

condition属性で条件を指定する

@Cacheable、@CacheEvict、@CachePutのアノテーションはすべてcondition属性を持っています。名前から推測できるように、@Cacheable、@CacheEvict、@CachePutが動作する条件を指定できます。これはkeyと同様にSpELが使用できます。以下のように使います。

class Author {
    String name
}
class AuthorService {

    @Cacheable(value = 'authors', condition = "#name.length() > 5")
    def get(name) {
        Author.findByName(name)
    }

}

この例では仮引数のnameの長さが5文字以上の場合キャッシュします。
テストを書いてみます。

class AuthorServiceSpec extends IntegrationSpec {

    def authorService
    def grailsCacheManager

    def cleanup() {
        grailsCacheManager.destroyCache('authors')
    }

    def "conditionでキャッシュ条件を指定する"() {
        given:
        def author1 = new Author(name: "4444").save(flush: true)
        def author2 = new Author(name: "55555").save(flush: true)
        def author3 = new Author(name: "666666").save(flush: true)
        def author4 = new Author(name: "7777777").save(flush: true)

        when:
        authorService.get(author1.name)
        authorService.get(author2.name)
        authorService.get(author3.name)
        authorService.get(author4.name)

        then: "名前が5文字以上のAuthorのみキャッシュされている"
        authorsCache == [(author3.name): author3, (author4.name): author4]
    }

    private getAuthorsCache() {
        grailsCacheManager.getCache('authors').nativeCache
    }

}

アノテーションのvalueの型はStringではなくString[]である

これは何を意味するかというという、複数にキャッシュをすると複数にキャッシュに対して操作ができます。例えば複数キャシュを同時に削除するには以下のようにします。

class AuthorService {
    ....
    @CacheEvict(value = ['authors', 'books'], allEntries = true)
    def clearAll() {}

}

'authors'のキャッシュと、'books'のキャッシュが同時に消えます。テストを書いてみます。

    def "複数のキャッシュを同時に削除する"() {
        given: "authorのキャッシュを準備"
        def author = new Author(name: "xxxxxx").save(flush: true)
        authorService.get(author.name)

        and: "authorがキャッシュされていること"
        assert authorsCache == [(author.name): author]

        and: "bookのキャッシュを準備"
        def book = new Book(title: 'yyyy').save(flush: true)
        bookService.get(book.id)

        and: "bookがキャッシュされていること"
        assert booksCache == [(book.id): book]

        when: "authorsとbooksのキャッシュを同時に削除"
        authorService.clearAll()

        then: "両方のキャッシュが削除されていること"
        authorsCache == [:]
        booksCache == [:]
    }

ではでは、長くなりましたがおわり。

GrailsでJSONの独自Marshallerを登録する

元ネタ
http://compiledammit.com/2012/08/16/custom-json-marshalling-in-grails-done-right/

有名な話なのかもしれませんが、独自Marshaller登録できるんですね。知らなかった。

GrailsではJSONレスポンス書き出し方に代表的な2つのやり方が存在します。
http://grails.org/doc/latest/guide/single.html#xmlAndJSON

  • renderメソッド使う方法
  • 自動Marshallingする方法

以下の様なドメインがあったとして

class Author {

    String name
    String email

    static hasMany = [books: Book]
}
class Book {

    String title

    static belongsTo = Author

}

これを後者の方はこんなかんじに書けます。

render Author.list() as JSON

実際に出力されるJSONは以下のようになります。

[
  {
    "class":"org.yamkazu.Author",
    "id":1,
    "books":[{"class":"Book","id":2},{"class":"Book","id":1}],
    "name":"test1",
    "email":"test1@example.com"
  },{
    "class":"org.yamkazu.Author",
    "id":2,
    "books":[],"name":"test2",
    "email":"test2@example.com"
  }
]

as JSONを使うと手軽な分、classとか必要ない情報が含まれてしまったり、例えばemailとかユーザは見せてはいけないのに、ドメインに含まれているため出力されてしまうといったように、気軽にas JSONすると良からぬ事態を引き起こしかねません。また関連ドメインのプロパティはidしか情報が出力されないといった制約もあります。

そこで独自のMarshallerです。grails.converters.JSON#registerObjectMarshallerのメソッドで登録できます。
f:id:yamkazu:20120831231539p:plain

一番手軽なのはクラスと、Closureを引数に取るやつです。こいつをBootstrapでも登録してもいいし、最初に紹介したURLのように独自のSpringBeanで登録させても良いです。

今回はemailを外部に暴露したくなかったのと、classは不要なので除去、あと関連先のbookのtitleまで含みたいので以下の様に登録してみました。

JSON.registerObjectMarshaller(Author) { Author author ->
    return [
        id: author.id,
        name: author.name,
        books: author.books.collect { Book book ->
            [
                id: book.id,
                title: book.title
            ]
        }
    ]
}

これで出力されるJSONは以下のようになります。

[
  {
    "id":1,
    "name":"test1",
    "books":[{"id":2,"title":"title1"},{"id":1,"title":"title2"}]
  },{
    "id":2,
    "name":"test2",
    "books":[]
  }
]

複数箇所で該当ドメインクラスのJSONレンダリングを必要とするといった場合や、絶対に外に漏れていけないプロパティがある場合に有効な手段じゃないでしょうか!

Mountain Lionで~/.MacOSX/environment.plistがきかない

http://d.hatena.ne.jp/y_sumida/20120805/1344134360
をみてて~/.MacOSX/environment.plistでグローバルに設定できたよなと思いつつ、ローカルの環境を確認してみるとうまく動いていない...

Mountain Lion以前までは以下の方法で回避していたのですが
https://blogs.oracle.com/katakai/entry/netbeans_and_java_for_mac2
どうもMountain Lionからは~/.MacOSX/environment.plistを広なくなった模様(前からサポート停止されてた?)。いろいろぐぐってみると/etc/launchd.confに書けとのこと。

デフォルトではファイルすら存在しないので、ファイルを作ってOS再起動。

setenv JAVA_HOME /Library/Java/JavaVirtualMachines/1.7.0.jdk/Contents/Home
setenv _JAVA_OPTIONS -Dfile.encoding=UTF-8

すると

$ groovy -version
Picked up _JAVA_OPTIONS: -Dfile.encoding=UTF-8
Groovy Version: 2.0.1 JVM: 1.7.0_05 Vendor: Oracle Corporation OS: Mac OS X

_JAVA_OPTIONS拾ってくれました!Intellij IDEA上で日本語テスト名もこれで大丈夫でした。

2013年5月13日追記

http://piyopiyoducky.net/blog/2013/04/13/java-system-properties-setting-and-character-encoding/

によるとJava7からLANGの設定を拾ってくれるため/etc/launchd.confに以下のように書けば良いとのこと。

setenv LANG ja_JP.UTF-8

GrailsでドメインクラスにMapのプロパティを定義するとどうのようなスキーマになるか

class MapHolder {

    Map mapValues

}

schema-exportすると以下になりました。

create table map_holder (
    id bigint generated by default as identity,
    version bigint not null,
    primary key (id)
);

create table map_holder_map_values (
    map_values bigint,
    map_values_idx varchar(255),
    map_values_elt varchar(255) not null
);

デフォルトだとMapの型がString,Stringの値を管理できる模様。

Grailsでone-to-manyの関連をラッパークラス型で定義するとどの様なスキーマになるか

class WrapperValueHolder {

    static hasMany = [stringValues: String, integerValues: Integer, booleanValues: Boolean]

}

schema-exportしてみる。

create table wrapper_value_holder (
    id bigint generated by default as identity,
    version bigint not null,
    primary key (id)
);

create table wrapper_value_holder_boolean_values (
    wrapper_value_holder_id bigint,
    boolean_values_boolean boolean
);

create table wrapper_value_holder_integer_values (
    wrapper_value_holder_id bigint,
    integer_values_integer integer
);

create table wrapper_value_holder_string_values (
    wrapper_value_holder_id bigint,
    string_values_string varchar(255)
);

普通に使えました。

※2012/7/23 修正
プリミティブ型と書いてましたが、プリミティブ型ではないので文言を修正しました

Grailsの関連の型での動作の違いを理解する

ドメイン間の関連の型をどの様に設定するかでの挙動の違いです。リファレンスに書いてあることですが、いろいろ動かしながら検証してみました。

ログとかだらだら長くて見にくいですが、面白いので貼り付けときました。

Bookドメイン

class Book {

    String title

    static belongsTo = [author: Author]

}

Authorドメイン

class Author {

    String name

    static hasMany = [books: Book]

}

このときのスキーマは以下のようになります(H2の場合)。

create table author (
    id bigint generated by default as identity,
    version bigint not null,
    name varchar(255) not null,
    primary key (id)
);

create table book (
    id bigint generated by default as identity,
    version bigint not null,
    author_id bigint not null,
    title varchar(255) not null,
    primary key (id)
);

相互に関連が設定されているのでmappingテーブルが作成されていません。

Authorでbooksというone-to-manyな関連を定義していますが、特に型を指定していない場合はデフォルトjava.util.Setが使われます。

ここでテストを実行してみます。

class AuthorSpec extends IntegrationSpec {

    def setup() {
        Author.withNewSession {
            def author = new Author(name: "dummy")
            author.addToBooks(new Book(title: "hoge"))
            author.addToBooks(new Book(title: "foo"))
            author.addToBooks(new Book(title: "bar"))
            author.save()
        }
    }

    def "addToBooksでbookを保存する"() {
        setup:
        def author = Author.findByName("dummy")

        when:
        author.addToBooks(new Book(title: "test"))
        author.save(flush: true)

        then:
        Book.findByTitle("test").author == author
    }

}

実際に実行しみるとテストメソッドでは以下のSQLが発行されます。

2012-07-18 16:52:19,360 [main] DEBUG hibernate.SQL  - 
    select
        this_.id as id1_0_,
        this_.version as version1_0_,
        this_.name as name1_0_ 
    from
        author this_ 
    where
        this_.name=? limit ?
2012-07-18 16:52:19,408 [main] DEBUG hibernate.SQL  - 
    select
        books0_.author_id as author3_1_1_,
        books0_.id as id1_,
        books0_.id as id0_0_,
        books0_.version as version0_0_,
        books0_.author_id as author3_0_0_,
        books0_.title as title0_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?
2012-07-18 16:52:19,471 [main] DEBUG hibernate.SQL  - 
    insert 
    into
        book
        (id, version, author_id, title) 
    values
        (null, ?, ?, ?)
2012-07-18 16:52:19,507 [main] DEBUG hibernate.SQL  - 
    update
        author 
    set
        version=?,
        name=? 
    where
        id=? 
        and version=?
2012-07-18 16:52:19,520 [main] DEBUG hibernate.SQL  - 
    select
        this_.id as id0_0_,
        this_.version as version0_0_,
        this_.author_id as author3_0_0_,
        this_.title as title0_0_ 
    from
        book this_ 
    where
        this_.title=? limit ?

面白いのはauthor.addToBooksしたタイミンで一度、そのときの関連全てを取得するためのselectが走ることです。これは関連がjava.util.Setが定義されているからで、books内のエンティティがユニークであることを保証するために、関連がこのタイミングでレイジーにロードされます。試しに、重複した要素を追加してみます。

    def "addToBooksで重複したbookを追加する"() {
        setup:
        def author = Author.findByName("dummy")
        def book = Book.findByTitle("hoge")

        when:
        author.addToBooks(book)
        author.save(flush: true)

        then:
        author.books.size() == 3
    }

実行すると以下の様なSQLが実行されます。

2012-07-18 19:05:19,917 [main] DEBUG hibernate.SQL  - 
    select
        this_.id as id0_0_,
        this_.version as version0_0_,
        this_.name as name0_0_ 
    from
        author this_ 
    where
        this_.name=? limit ?
2012-07-18 19:05:20,009 [main] DEBUG hibernate.SQL  - 
    select
        this_.id as id1_0_,
        this_.version as version1_0_,
        this_.author_id as author3_1_0_,
        this_.title as title1_0_ 
    from
        book this_ 
    where
        this_.title=? limit ?
2012-07-18 19:05:20,036 [main] DEBUG hibernate.SQL  - 
    select
        books0_.author_id as author3_0_1_,
        books0_.id as id1_,
        books0_.id as id1_0_,
        books0_.version as version1_0_,
        books0_.author_id as author3_1_0_,
        books0_.title as title1_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?

author.addToBooks(book)で要素を追加したタイミングで関連を取得していますが、すでに追加されている要素なので、重複して追加されずsave()しても特に何も起きません。これとは別に明示的にSortedSetで宣言して関連先のcompareToを実装して、ソート済み状態にすることも出来ます。

次にAuthorドメインでbooksの型を明示的にListに設定してみます。

class Author {

    String name
    
    List books

    static hasMany = [books: Book]

}

こんどは以下の様なスキーマが生成されるようになります。

create table author (
    id bigint generated by default as identity,
    version bigint not null,
    name varchar(255) not null,
    primary key (id)
);

create table book (
    id bigint generated by default as identity,
    version bigint not null,
    author_id bigint not null,
    title varchar(255) not null,
    books_idx integer,
    primary key (id)
);

books_idxというbooksの順序を保存するためのカラムが追加されているのが特徴的です。こいつの動作を検証するテストを書いてみます。

def "booksに追加したり、ソートしたり、削除したり"() {
    setup:
    def author = Author.findByName("dummy")

    when:
    println "新規にBookを追加 ${'>' * 100}"
    author.addToBooks(new Book(title: "test"))
    author.save(flush: true)

    then:
    Author.withNewSession { Author.get(author.id).books*.title } == ["hoge", "foo", "bar", "test"]

    when:
    println "ソートして保存 ${'>' * 100}"
    author.books.sort { it.title }
    author.save(flush: true)

    then:
    Author.withNewSession { Author.get(author.id).books*.title } == ["bar", "foo", "hoge", "test"]

    when:
    println "要素を削除して保存 ${'>' * 100}"
    author.books.remove(1).delete()
    author.save(flush: true)

    then:
    Author.withNewSession { Author.get(author.id).books*.title } == ["bar", "hoge", "test"]
}

ちょっとださいけどログがみやすいようにprint仕込んでます。あとthenで検証する際に1次キャッシュを明示的に使用しないようにwithNewSessionでクエリを実行しています。これを実行すると以下の様なログになりました(バインドされている値も一緒にだしているのでかなり長めです...)。

2012-07-19 23:34:07,569 [main] DEBUG org.hibernate.SQL - 
    select
        this_.id as id1_0_,
        this_.version as version1_0_,
        this_.name as name1_0_ 
    from
        author this_ 
    where
        this_.name=? limit ?
2012-07-19 23:34:07,569 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [VARCHAR] - dummy
2012-07-19 23:34:07,575 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id1_0_]
2012-07-19 23:34:07,577 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version1_0_]
2012-07-19 23:34:07,578 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [dummy] as column [name1_0_]
新規にBookを追加 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2012-07-19 23:34:07,605 [main] DEBUG org.hibernate.SQL - 
    select
        books0_.author_id as author3_1_1_,
        books0_.id as id1_,
        books0_.books_idx as books5_1_,
        books0_.id as id5_0_,
        books0_.version as version5_0_,
        books0_.author_id as author3_5_0_,
        books0_.title as title5_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?
2012-07-19 23:34:07,605 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,608 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id5_0_]
2012-07-19 23:34:07,609 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,609 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,609 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [hoge] as column [title5_0_]
2012-07-19 23:34:07,609 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,609 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id1_]
2012-07-19 23:34:07,612 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [books5_1_]
2012-07-19 23:34:07,612 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [id5_0_]
2012-07-19 23:34:07,612 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,612 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [foo] as column [title5_0_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [id1_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [books5_1_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id5_0_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [bar] as column [title5_0_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id1_]
2012-07-19 23:34:07,613 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [books5_1_]
2012-07-19 23:34:07,643 [main] DEBUG org.hibernate.SQL - 
    insert 
    into
        book
        (id, version, title, author_id, books_idx) 
    values
        (null, ?, ?, ?, ?)
2012-07-19 23:34:07,643 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 0
2012-07-19 23:34:07,643 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [VARCHAR] - test
2012-07-19 23:34:07,644 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 1
2012-07-19 23:34:07,645 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [4] as [INTEGER] - 3
2012-07-19 23:34:07,668 [main] DEBUG org.hibernate.SQL - 
    update
        author 
    set
        version=?,
        name=? 
    where
        id=? 
        and version=?
2012-07-19 23:34:07,669 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,669 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [VARCHAR] - dummy
2012-07-19 23:34:07,669 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 1
2012-07-19 23:34:07,669 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [4] as [BIGINT] - 0
2012-07-19 23:34:07,673 [main] DEBUG org.hibernate.SQL - 
    update
        book 
    set
        author_id=?,
        books_idx=? 
    where
        id=?
2012-07-19 23:34:07,673 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,673 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [INTEGER] - 3
2012-07-19 23:34:07,673 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 4
2012-07-19 23:34:07,688 [main] DEBUG org.hibernate.SQL - 
    select
        author0_.id as id1_0_,
        author0_.version as version1_0_,
        author0_.name as name1_0_ 
    from
        author author0_ 
    where
        author0_.id=?
2012-07-19 23:34:07,688 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,689 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [version1_0_]
2012-07-19 23:34:07,689 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [dummy] as column [name1_0_]
2012-07-19 23:34:07,692 [main] DEBUG org.hibernate.SQL - 
    select
        books0_.author_id as author3_1_1_,
        books0_.id as id1_,
        books0_.books_idx as books5_1_,
        books0_.id as id5_0_,
        books0_.version as version5_0_,
        books0_.author_id as author3_5_0_,
        books0_.title as title5_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?
2012-07-19 23:34:07,693 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,694 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id5_0_]
2012-07-19 23:34:07,697 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,697 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,697 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [hoge] as column [title5_0_]
2012-07-19 23:34:07,697 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id1_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [books5_1_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [id5_0_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [foo] as column [title5_0_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [id1_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [books5_1_]
2012-07-19 23:34:07,698 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [bar] as column [title5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id1_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [books5_1_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [4] as column [id5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [test] as column [title5_0_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [4] as column [id1_]
2012-07-19 23:34:07,699 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [books5_1_]
ソートして保存 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2012-07-19 23:34:07,744 [main] DEBUG org.hibernate.SQL - 
    update
        author 
    set
        version=?,
        name=? 
    where
        id=? 
        and version=?
2012-07-19 23:34:07,746 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 2
2012-07-19 23:34:07,746 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [VARCHAR] - dummy
2012-07-19 23:34:07,746 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 1
2012-07-19 23:34:07,746 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [4] as [BIGINT] - 1
2012-07-19 23:34:07,747 [main] DEBUG org.hibernate.SQL - 
    update
        book 
    set
        author_id=?,
        books_idx=? 
    where
        id=?
2012-07-19 23:34:07,747 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,747 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [INTEGER] - 0
2012-07-19 23:34:07,747 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 3
2012-07-19 23:34:07,747 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,747 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [INTEGER] - 2
2012-07-19 23:34:07,748 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 1
2012-07-19 23:34:07,757 [main] DEBUG org.hibernate.SQL - 
    select
        author0_.id as id1_0_,
        author0_.version as version1_0_,
        author0_.name as name1_0_ 
    from
        author author0_ 
    where
        author0_.id=?
2012-07-19 23:34:07,758 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,758 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [version1_0_]
2012-07-19 23:34:07,758 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [dummy] as column [name1_0_]
2012-07-19 23:34:07,759 [main] DEBUG org.hibernate.SQL - 
    select
        books0_.author_id as author3_1_1_,
        books0_.id as id1_,
        books0_.books_idx as books5_1_,
        books0_.id as id5_0_,
        books0_.version as version5_0_,
        books0_.author_id as author3_5_0_,
        books0_.title as title5_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?
2012-07-19 23:34:07,760 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,761 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id5_0_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [hoge] as column [title5_0_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id1_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [books5_1_]
2012-07-19 23:34:07,762 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [id5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [foo] as column [title5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [id1_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [books5_1_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [bar] as column [title5_0_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,763 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id1_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [books5_1_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [4] as column [id5_0_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [test] as column [title5_0_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,764 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [4] as column [id1_]
2012-07-19 23:34:07,765 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [books5_1_]
要素を削除して保存 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2012-07-19 23:34:07,789 [main] DEBUG org.hibernate.SQL - 
    update
        author 
    set
        version=?,
        name=? 
    where
        id=? 
        and version=?
2012-07-19 23:34:07,790 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 3
2012-07-19 23:34:07,790 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [VARCHAR] - dummy
2012-07-19 23:34:07,790 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 1
2012-07-19 23:34:07,790 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [4] as [BIGINT] - 2
2012-07-19 23:34:07,790 [main] DEBUG org.hibernate.SQL - 
    update
        book 
    set
        author_id=?,
        books_idx=? 
    where
        id=?
2012-07-19 23:34:07,791 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,791 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [INTEGER] - 1
2012-07-19 23:34:07,791 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 1
2012-07-19 23:34:07,791 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,791 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [INTEGER] - 2
2012-07-19 23:34:07,791 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [3] as [BIGINT] - 4
2012-07-19 23:34:07,792 [main] DEBUG org.hibernate.SQL - 
    delete 
    from
        book 
    where
        id=? 
        and version=?
2012-07-19 23:34:07,793 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 2
2012-07-19 23:34:07,793 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [2] as [BIGINT] - 0
2012-07-19 23:34:07,810 [main] DEBUG org.hibernate.SQL - 
    select
        author0_.id as id1_0_,
        author0_.version as version1_0_,
        author0_.name as name1_0_ 
    from
        author author0_ 
    where
        author0_.id=?
2012-07-19 23:34:07,812 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,812 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [version1_0_]
2012-07-19 23:34:07,812 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [dummy] as column [name1_0_]
2012-07-19 23:34:07,815 [main] DEBUG org.hibernate.SQL - 
    select
        books0_.author_id as author3_1_1_,
        books0_.id as id1_,
        books0_.books_idx as books5_1_,
        books0_.id as id5_0_,
        books0_.version as version5_0_,
        books0_.author_id as author3_5_0_,
        books0_.title as title5_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?
2012-07-19 23:34:07,815 [main] TRACE org.hibernate.type.descriptor.sql.BasicBinder - binding parameter [1] as [BIGINT] - 1
2012-07-19 23:34:07,816 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id5_0_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [hoge] as column [title5_0_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [id1_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [books5_1_]
2012-07-19 23:34:07,818 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [bar] as column [title5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [3] as column [id1_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [books5_1_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [4] as column [id5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [0] as column [version5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [test] as column [title5_0_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [1] as column [author3_1_1_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [4] as column [id1_]
2012-07-19 23:34:07,819 [main] TRACE org.hibernate.type.descriptor.sql.BasicExtractor - found [2] as column [books5_1_]

これからわかったことはaddToBooksのタイミングで一度関連をレイジーに取りに行く、その時のクエリにidxでorderbyしていない、これはgrails?側でソートきかせている?あと、ソートしたり、要素を消したりするとidxのupdateが走るといったとこでしょうか。これは意図せず大量のUPDATE文走らせそうで注意。

こんどはHibernateのBag型をつかってみます。Grailsでこれを使うにはCollection型で宣言する必要があります。

class Author {

    String name

    Collection books

    static hasMany = [books: Book]

}

んで以下のテストを実行。

def "addToBooksでbookを保存する"() {
    setup:
    def author = Author.findByName("dummy")

    when:
    author.addToBooks(new Book(title: "test"))
    author.save(flush: true)

    then:
    Author.withNewSession { Author.get(author.id).books*.title } as Set == ['hoge', 'foo', 'bar', 'test'] as Set
}

実行ログ。

2012-07-21 14:53:23,117 [main] DEBUG org.hibernate.SQL - 
    select
        this_.id as id1_0_,
        this_.version as version1_0_,
        this_.name as name1_0_ 
    from
        author this_ 
    where
        this_.name=? limit ?
2012-07-21 14:53:23,168 [main] DEBUG org.hibernate.SQL - 
    insert 
    into
        book
        (id, version, author_id, title) 
    values
        (null, ?, ?, ?)
2012-07-21 14:53:23,196 [main] DEBUG org.hibernate.SQL - 
    update
        author 
    set
        version=?,
        name=? 
    where
        id=? 
        and version=?
2012-07-21 14:53:23,214 [main] DEBUG org.hibernate.SQL - 
    select
        author0_.id as id1_0_,
        author0_.version as version1_0_,
        author0_.name as name1_0_ 
    from
        author author0_ 
    where
        author0_.id=?
2012-07-21 14:53:23,218 [main] DEBUG org.hibernate.SQL - 
    select
        books0_.author_id as author3_1_1_,
        books0_.id as id1_,
        books0_.id as id3_0_,
        books0_.version as version3_0_,
        books0_.author_id as author3_3_0_,
        books0_.title as title3_0_ 
    from
        book books0_ 
    where
        books0_.author_id=?

特徴はaddToBooksしたタイミングで、関連を引っ張るselectが走りません。これはBag型がソート、重複を管理しないためです。

ということで改めてSet、List、Collectionを比較してみると、特に制約がないならCollectionを使うとパフォーマンスが一番良い。

ソート順を保持する必要があるなら、SetでSortedSetを使用するか、Listを使う必要がある。Listは仕組み的に必ず関連を一度すべて取得しなければならないが、Setのほうが回避方法がある。

def "addToBooksでbookを保存する"() {
    setup:
    def author = Author.findByName("dummy")

    when:
    def book = new Book(title: "test")
    book.author = author
    book.save(flush: true)

    then:
    Author.withNewSession { Author.get(author.id).books*.title } as Set == ['hoge', 'foo', 'bar', 'test'] as Set
}

といった具合にauthor経由でカスケードさせるのではなく単にbookを保存すれば、余計なクエリーが走らないため、パフォーマンスが良い。Listは上記のように保存できない。

とそれぞれ特徴があるので、用途に合わせて使う必要がありますが、きちんと理解していないと、意図せず大量の関連を取得するSELECTや、順番を保持するために大量のUPDATEが走ることになるので注意が必要です。

GrailsのTaglib使っててid属性がどこかへいってしまう

htmlのid属性と、grailsのlink生成のためのドメインIDが混在していてややこしいのですが、例えばg:link

<a href="/appname/book/list" id="book-list">book list</a>

というようなHTMLを期待して

<g:link controller="book" action="list" id="book-list">book list</g:link>

といういうふうにg:linkを使うと実際には

<a href="/appname/book/list/book-list">book list</a>

となってしまいます。これをg:linkで回避するにはidではなくelementIdを指定します。

<g:link controller="book" action="list" elementId="book-list">book list</g:link>

そうすると期待する

<a href="/appname/book/list" id="book-list">book list</a>

になります。

g:formの場合はまた、ちょっと動作が違っていて

<g:form controller="book" action="create" id="create-book">
  ...
</g:form>

ではなく

<g:form url="[controller: 'book', action: 'create']" id="create-book">
  ...
</g:form>

というふうにurl属性を使用すると回避できます。なぜかこちらidのままでおk(なんで統一されていなの?)。

全部調べてませんが、他のタグでも困ったらリファレンス参照するか、grailsのtaglibのソースを探ると良いです。