From: <leg...@at...> - 2003-12-27 13:50:26
|
Message: The following issue has been re-assigned. Assignee: Gavin King (mailto:ga...@hi...) Assigner: Max Rydahl Andersen (mailto:xa...@xa...) Date: Sat, 27 Dec 2003 7:50 AM Comment: The solution is probably not to trim() since we really do not like to change the scalars returned via JDBC - some people might EXPECT the padded stuff to be there! I guess the issue relates to the new caching stuff, maybe one of our cache providers does the trim or something ? Throwing it to gavin ;) --------------------------------------------------------------------- View the issue: http://opensource.atlassian.com/projects/hibernate/secure/ViewIssue.jspa?key=HB-582 Here is an overview of the issue: --------------------------------------------------------------------- Key: HB-582 Summary: Extra ' ' when read char type field in SQLServer 2000 Type: Bug Status: Open Priority: Critical Project: Hibernate2 Components: core Versions: 2.1.1 Assignee: Gavin King Reporter: Shining Created: Sat, 27 Dec 2003 7:33 AM Updated: Sat, 27 Dec 2003 7:50 AM Environment: Windows2000 Professional with SP4, JDK 1.4.2_02, Eclipse 2.1.2 Hibernate 2.1.1 SQLServer 2000 Desktop with SP2, Microsoft SQLServer JDBC Driver SP2 Description: There's a strange phenomenon when using SQLServer2000. When you read a char field through JDBC(ODBC is the same), the result were padded with extra blankspace, the length of blank space is equal to the length of data character subtract from the length of the field. for example: field type is: char(10), data character is '1', the result of read will be '1 '. The same reading operator in MySQL is correct. Other Database server have not been tested. When I test the sample code(figure 1) with hibernate 2.1.1, I found a bug that course collection lost when load a class with the char type id and a collection field with the same id as the id column. Hibernate 2.1.1 DEBUG&OUTPUT Information ---------------------------------------------------------------------------------------------------------------------------------------- 19:49:19,902 INFO Environment:432 - Hibernate 2.1.1 19:49:19,952 INFO Environment:461 - hibernate.properties not found 19:49:20,042 INFO Environment:481 - using CGLIB reflection optimizer 19:49:20,102 INFO Configuration:843 - configuring from resource: /hibernate.cfg.xml 19:49:20,112 INFO Configuration:815 - Configuration resource: /hibernate.cfg.xml ...... 19:49:37,428 DEBUG SessionFactoryImpl:196 - instantiated session factory 19:49:37,729 DEBUG SessionImpl:528 - opened session 19:49:37,739 DEBUG SessionImpl:1913 - loading [test.Group#1] 19:49:37,739 DEBUG SessionImpl:2010 - attempting to resolve [test.Group#1] 19:49:37,759 DEBUG SessionImpl:2043 - object not resolved in any cache [test.Group#1] 19:49:37,759 DEBUG EntityPersister:417 - Materializing entity: [test.Group#1] 19:49:37,779 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:49:37,779 DEBUG DriverManagerConnectionProvider:78 - total checked-out connections: 0 19:49:37,789 DEBUG DriverManagerConnectionProvider:84 - using pooled JDBC connection, pool size: 0 19:49:37,789 DEBUG SQL:223 - select group0_.group_id as group_id0_, group0_.group_name as group_name0_ from tbl_group group0_ where group0_.group_id=? Hibernate: select group0_.group_id as group_id0_, group0_.group_name as group_name0_ from tbl_group group0_ where group0_.group_id=? 19:49:37,789 DEBUG BatcherImpl:227 - preparing statement 19:49:38,239 DEBUG StringType:46 - binding '1' to parameter: 1 19:49:38,590 DEBUG Loader:196 - processing result set 19:49:38,590 DEBUG Loader:404 - result row: 1 19:49:38,610 DEBUG Loader:535 - Initializing object from ResultSet: 1 19:49:38,630 DEBUG Loader:604 - Hydrating entity: test.Group#1 19:49:38,650 DEBUG StringType:68 - returning 'group1 ' as column: group_name0_ 19:49:38,660 DEBUG Loader:225 - done processing result set (1 rows) 19:49:38,680 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:49:38,680 DEBUG BatcherImpl:240 - closing statement 19:49:38,690 DEBUG Loader:238 - total objects hydrated: 1 19:49:38,700 DEBUG SessionImpl:2129 - resolving associations for [test.Group#1] 19:49:38,720 DEBUG SessionImpl:3746 - collection not cached 19:49:38,760 DEBUG SessionImpl:2153 - done materializing entity [test.Group#1] 19:49:38,760 DEBUG SessionImpl:3000 - initializing non-lazy collections 19:49:38,760 DEBUG SessionImpl:3132 - initializing collection [test.Group.persons#1] 19:49:38,770 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:49:38,770 DEBUG SQL:223 - select persons0_.person_id as person_id__, persons0_.group_id as group_id__, persons0_.person_id as person_id0_, persons0_.person_name as person_n2_0_, persons0_.group_id as group_id0_ from tbl_person persons0_ where persons0_.group_id=? Hibernate: select persons0_.person_id as person_id__, persons0_.group_id as group_id__, persons0_.person_id as person_id0_, persons0_.person_name as person_n2_0_, persons0_.group_id as group_id0_ from tbl_person persons0_ where persons0_.group_id=? 19:49:38,790 DEBUG BatcherImpl:227 - preparing statement 19:49:38,790 DEBUG StringType:46 - binding '1' to parameter: 1 19:49:38,810 DEBUG Loader:326 - result set contains (possibly empty) collection: [test.Group.persons#1] 19:49:38,810 DEBUG SessionImpl:2902 - uninitialized collection: initializing 19:49:38,830 DEBUG Loader:196 - processing result set 19:49:38,840 DEBUG StringType:68 - returning '11 ' as column: person_id0_ 19:49:38,840 DEBUG Loader:404 - result row: 11 19:49:38,850 DEBUG Loader:535 - Initializing object from ResultSet: 11 19:49:38,850 DEBUG Loader:604 - Hydrating entity: test.Person#11 19:49:38,860 DEBUG StringType:68 - returning 'person11 ' as column: person_n2_0_ 19:49:38,860 DEBUG StringType:68 - returning '1 ' as column: group_id0_ 19:49:38,860 DEBUG StringType:68 - returning '1 ' as column: group_id__ 19:49:38,870 DEBUG Loader:288 - found row of collection: [test.Group.persons#1 ] 19:49:38,870 DEBUG SessionImpl:2914 - new collection: instantiating 19:49:38,870 DEBUG StringType:68 - returning '11 ' as column: person_id__ 19:49:38,880 DEBUG SessionImpl:1913 - loading [test.Person#11 ] 19:49:38,890 DEBUG SessionImpl:2010 - attempting to resolve [test.Person#11 ] 19:49:38,910 DEBUG SessionImpl:2026 - resolved object in session cache [test.Person#11 ] 19:49:38,910 DEBUG StringType:68 - returning '12 ' as column: person_id0_ 19:49:38,910 DEBUG Loader:404 - result row: 12 19:49:38,920 DEBUG Loader:535 - Initializing object from ResultSet: 12 19:49:38,920 DEBUG Loader:604 - Hydrating entity: test.Person#12 19:49:38,930 DEBUG StringType:68 - returning 'person12 ' as column: person_n2_0_ 19:49:38,930 DEBUG StringType:68 - returning '1 ' as column: group_id0_ 19:49:38,960 DEBUG StringType:68 - returning '1 ' as column: group_id__ 19:49:38,960 DEBUG Loader:288 - found row of collection: [test.Group.persons#1 ] 19:49:38,960 DEBUG SessionImpl:2925 - reading row 19:49:38,960 DEBUG StringType:68 - returning '12 ' as column: person_id__ 19:49:39,001 DEBUG SessionImpl:1913 - loading [test.Person#12 ] 19:49:39,001 DEBUG SessionImpl:2010 - attempting to resolve [test.Person#12 ] 19:49:39,011 DEBUG SessionImpl:2026 - resolved object in session cache [test.Person#12 ] 19:49:39,011 DEBUG StringType:68 - returning '13 ' as column: person_id0_ 19:49:39,011 DEBUG Loader:404 - result row: 13 19:49:39,021 DEBUG Loader:535 - Initializing object from ResultSet: 13 19:49:39,021 DEBUG Loader:604 - Hydrating entity: test.Person#13 19:49:39,021 DEBUG StringType:68 - returning 'person13 ' as column: person_n2_0_ 19:49:39,021 DEBUG StringType:68 - returning '1 ' as column: group_id0_ 19:49:39,031 DEBUG StringType:68 - returning '1 ' as column: group_id__ 19:49:39,031 DEBUG Loader:288 - found row of collection: [test.Group.persons#1 ] 19:49:39,041 DEBUG SessionImpl:2925 - reading row 19:49:39,041 DEBUG StringType:68 - returning '13 ' as column: person_id__ 19:49:39,051 DEBUG SessionImpl:1913 - loading [test.Person#13 ] 19:49:39,071 DEBUG SessionImpl:2010 - attempting to resolve [test.Person#13 ] 19:49:39,071 DEBUG SessionImpl:2026 - resolved object in session cache [test.Person#13 ] 19:49:39,081 DEBUG StringType:68 - returning '14 ' as column: person_id0_ 19:49:39,091 DEBUG Loader:404 - result row: 14 19:49:39,091 DEBUG Loader:535 - Initializing object from ResultSet: 14 19:49:39,091 DEBUG Loader:604 - Hydrating entity: test.Person#14 19:49:39,091 DEBUG StringType:68 - returning 'person14 ' as column: person_n2_0_ 19:49:39,101 DEBUG StringType:68 - returning '1 ' as column: group_id0_ 19:49:39,101 DEBUG StringType:68 - returning '1 ' as column: group_id__ 19:49:39,111 DEBUG Loader:288 - found row of collection: [test.Group.persons#1 ] 19:49:39,111 DEBUG SessionImpl:2925 - reading row 19:49:39,111 DEBUG StringType:68 - returning '14 ' as column: person_id__ 19:49:39,131 DEBUG SessionImpl:1913 - loading [test.Person#14 ] 19:49:39,131 DEBUG SessionImpl:2010 - attempting to resolve [test.Person#14 ] 19:49:39,131 DEBUG SessionImpl:2026 - resolved object in session cache [test.Person#14 ] 19:49:39,131 DEBUG StringType:68 - returning '15 ' as column: person_id0_ 19:49:39,141 DEBUG Loader:404 - result row: 15 19:49:39,141 DEBUG Loader:535 - Initializing object from ResultSet: 15 19:49:39,151 DEBUG Loader:604 - Hydrating entity: test.Person#15 19:49:39,151 DEBUG StringType:68 - returning 'person15 ' as column: person_n2_0_ 19:49:39,161 DEBUG StringType:68 - returning '1 ' as column: group_id0_ 19:49:39,161 DEBUG StringType:68 - returning '1 ' as column: group_id__ 19:49:39,161 DEBUG Loader:288 - found row of collection: [test.Group.persons#1 ] 19:49:39,171 DEBUG SessionImpl:2925 - reading row 19:49:39,201 DEBUG StringType:68 - returning '15 ' as column: person_id__ 19:49:39,201 DEBUG SessionImpl:1913 - loading [test.Person#15 ] 19:49:39,211 DEBUG SessionImpl:2010 - attempting to resolve [test.Person#15 ] 19:49:39,211 DEBUG SessionImpl:2026 - resolved object in session cache [test.Person#15 ] 19:49:39,221 DEBUG Loader:225 - done processing result set (5 rows) 19:49:39,221 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:49:39,221 DEBUG BatcherImpl:240 - closing statement 19:49:39,231 DEBUG Loader:238 - total objects hydrated: 5 19:49:39,231 DEBUG SessionImpl:2129 - resolving associations for [test.Person#11 ] {**** 19:49:39,241 DEBUG SessionImpl:1913 - loading [test.Group#1 ] 19:49:39,241 DEBUG SessionImpl:2010 - attempting to resolve [test.Group#1 ] 19:49:39,241 DEBUG SessionImpl:2043 - object not resolved in any cache [test.Group#1 ] ***} 19:49:39,241 DEBUG EntityPersister:417 - Materializing entity: [test.Group#1 ] 19:49:39,251 DEBUG BatcherImpl:192 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:49:39,251 DEBUG SQL:223 - select group0_.group_id as group_id0_, group0_.group_name as group_name0_ from tbl_group group0_ where group0_.group_id=? Hibernate: select group0_.group_id as group_id0_, group0_.group_name as group_name0_ from tbl_group group0_ where group0_.group_id=? 19:49:39,261 DEBUG BatcherImpl:227 - preparing statement 19:49:39,261 DEBUG StringType:46 - binding '1 ' to parameter: 1 19:49:39,281 DEBUG Loader:196 - processing result set 19:49:39,281 DEBUG Loader:404 - result row: 1 19:49:39,281 DEBUG Loader:535 - Initializing object from ResultSet: 1 19:49:39,291 DEBUG Loader:604 - Hydrating entity: test.Group#1 19:49:39,321 DEBUG StringType:68 - returning 'group1 ' as column: group_name0_ 19:49:39,321 DEBUG Loader:225 - done processing result set (1 rows) 19:49:39,331 DEBUG BatcherImpl:199 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:49:39,331 DEBUG BatcherImpl:240 - closing statement 19:49:39,331 DEBUG Loader:238 - total objects hydrated: 1 19:49:39,341 DEBUG SessionImpl:2129 - resolving associations for [test.Group#1 ] 19:49:39,341 DEBUG SessionImpl:2153 - done materializing entity [test.Group#1 ] 19:49:39,351 DEBUG SessionImpl:2153 - done materializing entity [test.Person#11 ] 19:49:39,351 DEBUG SessionImpl:2129 - resolving associations for [test.Person#12 ] 19:49:39,351 DEBUG SessionImpl:1913 - loading [test.Group#1 ] 19:49:39,361 DEBUG SessionImpl:2010 - attempting to resolve [test.Group#1 ] 19:49:39,361 DEBUG SessionImpl:2026 - resolved object in session cache [test.Group#1 ] 19:49:39,371 DEBUG SessionImpl:2153 - done materializing entity [test.Person#12 ] 19:49:39,371 DEBUG SessionImpl:2129 - resolving associations for [test.Person#13 ] 19:49:39,381 DEBUG SessionImpl:1913 - loading [test.Group#1 ] 19:49:39,381 DEBUG SessionImpl:2010 - attempting to resolve [test.Group#1 ] 19:49:39,381 DEBUG SessionImpl:2026 - resolved object in session cache [test.Group#1 ] 19:49:39,381 DEBUG SessionImpl:2153 - done materializing entity [test.Person#13 ] 19:49:39,391 DEBUG SessionImpl:2129 - resolving associations for [test.Person#14 ] 19:49:39,391 DEBUG SessionImpl:1913 - loading [test.Group#1 ] 19:49:39,401 DEBUG SessionImpl:2010 - attempting to resolve [test.Group#1 ] 19:49:39,401 DEBUG SessionImpl:2026 - resolved object in session cache [test.Group#1 ] 19:49:39,411 DEBUG SessionImpl:2153 - done materializing entity [test.Person#14 ] 19:49:39,411 DEBUG SessionImpl:2129 - resolving associations for [test.Person#15 ] 19:49:39,441 DEBUG SessionImpl:1913 - loading [test.Group#1 ] 19:49:39,441 DEBUG SessionImpl:2010 - attempting to resolve [test.Group#1 ] 19:49:39,441 DEBUG SessionImpl:2026 - resolved object in session cache [test.Group#1 ] 19:49:39,451 DEBUG SessionImpl:2153 - done materializing entity [test.Person#15 ] 19:49:39,451 DEBUG SessionImpl:2961 - 2 collections were found in result set 19:49:39,461 DEBUG SessionImpl:2979 - collection fully initialized: [test.Group.persons#1 ] 19:49:39,461 DEBUG SessionImpl:2979 - collection fully initialized: [test.Group.persons#1] 19:49:39,461 DEBUG SessionImpl:2982 - 2 collections initialized ---------------------------------------------------------------------------------------------------------------------------------------- The message in {**** ***} show the problem reson. Because of the strange behavior of the jdbc driver of SQLServer, the object id in the cache is "1"(load(group.class, "1")), the id read through jdbc is "1 ", hibernate can not got the group object from the cache. I have test the same code with the hibernate version 2.0.3, the result is correct, the debug information is: Hibernate 2.0.3 DEBUG&OUTPUT Information ---------------------------------------------------------------------------------------------------------------------------------------- 19:40:48,701 INFO Environment:403 - Hibernate 2.0.3 19:40:48,721 INFO Environment:432 - hibernate.properties not found 19:40:48,751 INFO Environment:452 - using CGLIB reflection optimizer 19:40:48,761 INFO Environment:462 - JVM proxy support: true 19:40:48,791 INFO Configuration:703 - Configuration resource: /hibernate.cfg.xml 19:41:00,579 INFO SessionFactoryImpl:269 - Query language substitutions: {} ...... 19:41:00,589 DEBUG SessionFactoryImpl:281 - instantiated session factory 19:41:00,749 DEBUG SessionImpl:413 - opened session 19:41:00,769 DEBUG SessionImpl:1752 - loading [test.Group#1] 19:41:00,769 DEBUG SessionImpl:1843 - attempting to resolve [test.Group#1] 19:41:00,789 DEBUG SessionImpl:1887 - object not resolved in any cache [test.Group#1] 19:41:00,789 DEBUG EntityPersister:394 - Materializing entity: test.Group#1 19:41:00,799 DEBUG BatcherImpl:166 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:41:00,799 DEBUG DriverManagerConnectionProvider:77 - total checked-out connections: 0 19:41:00,799 DEBUG DriverManagerConnectionProvider:83 - using pooled JDBC connection, pool size: 0 19:41:00,809 DEBUG SessionFactoryImpl:526 - prepared statement get: select group0_.group_id as group_id, group0_.group_name as group_name from tbl_group group0_ where group0_.group_id=? Hibernate: select group0_.group_id as group_id, group0_.group_name as group_name from tbl_group group0_ where group0_.group_id=? 19:41:00,809 DEBUG SessionFactoryImpl:536 - preparing statement 19:41:01,160 DEBUG StringType:44 - binding '1' to parameter: 1 19:41:01,300 DEBUG Loader:148 - processing result set 19:41:01,310 DEBUG Loader:260 - result row: 1 19:41:01,310 DEBUG Loader:357 - Initializing object from ResultSet: 1 19:41:01,320 DEBUG Loader:413 - Hydrating entity: test.Group#1 19:41:01,320 DEBUG StringType:65 - returning 'group1 ' as column: group_name 19:41:01,330 DEBUG Loader:182 - done processing result set (1 rows) 19:41:01,340 DEBUG BatcherImpl:173 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:41:01,350 DEBUG SessionFactoryImpl:554 - closing statement 19:41:01,350 DEBUG Loader:195 - total objects hydrated: 1 19:41:01,350 DEBUG SessionImpl:1954 - resolving associations for [test.Group#1] 19:41:01,390 DEBUG SessionImpl:2888 - initializing collection [test.Group.persons#1] 19:41:01,390 DEBUG BatcherImpl:166 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:41:01,400 DEBUG SessionFactoryImpl:526 - prepared statement get: select tbl_pers0_.person_id as person_id__, tbl_pers0_.person_id as person_id, tbl_pers0_.person_name as person_n2_, tbl_pers0_.group_id as group_id from tbl_person tbl_pers0_ where tbl_pers0_.group_id=? Hibernate: select tbl_pers0_.person_id as person_id__, tbl_pers0_.person_id as person_id, tbl_pers0_.person_name as person_n2_, tbl_pers0_.group_id as group_id from tbl_person tbl_pers0_ where tbl_pers0_.group_id=? 19:41:01,400 DEBUG SessionFactoryImpl:536 - preparing statement 19:41:01,400 DEBUG StringType:44 - binding '1' to parameter: 1 19:41:01,430 DEBUG Loader:148 - processing result set 19:41:01,440 DEBUG StringType:65 - returning '11 ' as column: person_id 19:41:01,440 DEBUG Loader:260 - result row: 11 19:41:01,440 DEBUG Loader:357 - Initializing object from ResultSet: 11 19:41:01,440 DEBUG Loader:413 - Hydrating entity: test.Person#11 19:41:01,450 DEBUG StringType:65 - returning 'person11 ' as column: person_n2_ 19:41:01,450 DEBUG StringType:65 - returning '1 ' as column: group_id 19:41:01,450 DEBUG StringType:65 - returning '11 ' as column: person_id__ 19:41:01,460 DEBUG SessionImpl:1752 - loading [test.Person#11 ] 19:41:01,460 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#11 ] 19:41:01,470 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#11 ] 19:41:01,470 DEBUG StringType:65 - returning '12 ' as column: person_id 19:41:01,470 DEBUG Loader:260 - result row: 12 19:41:01,480 DEBUG Loader:357 - Initializing object from ResultSet: 12 19:41:01,480 DEBUG Loader:413 - Hydrating entity: test.Person#12 19:41:01,480 DEBUG StringType:65 - returning 'person12 ' as column: person_n2_ 19:41:01,480 DEBUG StringType:65 - returning '1 ' as column: group_id 19:41:01,490 DEBUG StringType:65 - returning '12 ' as column: person_id__ 19:41:01,500 DEBUG SessionImpl:1752 - loading [test.Person#12 ] 19:41:01,500 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#12 ] 19:41:01,500 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#12 ] 19:41:01,510 DEBUG StringType:65 - returning '13 ' as column: person_id 19:41:01,510 DEBUG Loader:260 - result row: 13 19:41:01,510 DEBUG Loader:357 - Initializing object from ResultSet: 13 19:41:01,530 DEBUG Loader:413 - Hydrating entity: test.Person#13 19:41:01,540 DEBUG StringType:65 - returning 'person13 ' as column: person_n2_ 19:41:01,540 DEBUG StringType:65 - returning '1 ' as column: group_id 19:41:01,540 DEBUG StringType:65 - returning '13 ' as column: person_id__ 19:41:01,550 DEBUG SessionImpl:1752 - loading [test.Person#13 ] 19:41:01,550 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#13 ] 19:41:01,550 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#13 ] 19:41:01,560 DEBUG StringType:65 - returning '14 ' as column: person_id 19:41:01,560 DEBUG Loader:260 - result row: 14 19:41:01,560 DEBUG Loader:357 - Initializing object from ResultSet: 14 19:41:01,570 DEBUG Loader:413 - Hydrating entity: test.Person#14 19:41:01,570 DEBUG StringType:65 - returning 'person14 ' as column: person_n2_ 19:41:01,570 DEBUG StringType:65 - returning '1 ' as column: group_id 19:41:01,580 DEBUG StringType:65 - returning '14 ' as column: person_id__ 19:41:01,580 DEBUG SessionImpl:1752 - loading [test.Person#14 ] 19:41:01,580 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#14 ] 19:41:01,590 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#14 ] 19:41:01,590 DEBUG StringType:65 - returning '15 ' as column: person_id 19:41:01,600 DEBUG Loader:260 - result row: 15 19:41:01,600 DEBUG Loader:357 - Initializing object from ResultSet: 15 19:41:01,600 DEBUG Loader:413 - Hydrating entity: test.Person#15 19:41:01,600 DEBUG StringType:65 - returning 'person15 ' as column: person_n2_ 19:41:01,610 DEBUG StringType:65 - returning '1 ' as column: group_id 19:41:01,610 DEBUG StringType:65 - returning '15 ' as column: person_id__ 19:41:01,620 DEBUG SessionImpl:1752 - loading [test.Person#15 ] 19:41:01,620 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#15 ] 19:41:01,630 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#15 ] 19:41:01,650 DEBUG Loader:182 - done processing result set (5 rows) 19:41:01,650 DEBUG BatcherImpl:173 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:41:01,650 DEBUG SessionFactoryImpl:554 - closing statement 19:41:01,650 DEBUG Loader:195 - total objects hydrated: 5 19:41:01,660 DEBUG SessionImpl:1954 - resolving associations for [test.Person#11 ] 19:41:01,660 DEBUG SessionImpl:1752 - loading [test.Group#1 ] 19:41:01,660 DEBUG SessionImpl:1843 - attempting to resolve [test.Group#1 ] 19:41:01,671 DEBUG SessionImpl:1887 - object not resolved in any cache [test.Group#1 ] 19:41:01,671 DEBUG EntityPersister:394 - Materializing entity: test.Group#1 19:41:01,681 DEBUG BatcherImpl:166 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:41:01,681 DEBUG SessionFactoryImpl:526 - prepared statement get: select group0_.group_id as group_id, group0_.group_name as group_name from tbl_group group0_ where group0_.group_id=? Hibernate: select group0_.group_id as group_id, group0_.group_name as group_name from tbl_group group0_ where group0_.group_id=? 19:41:01,681 DEBUG SessionFactoryImpl:536 - preparing statement 19:41:01,691 DEBUG StringType:44 - binding '1 ' to parameter: 1 19:41:01,691 DEBUG Loader:148 - processing result set 19:41:01,711 DEBUG Loader:260 - result row: 1 19:41:01,711 DEBUG Loader:357 - Initializing object from ResultSet: 1 19:41:01,711 DEBUG Loader:413 - Hydrating entity: test.Group#1 19:41:01,721 DEBUG StringType:65 - returning 'group1 ' as column: group_name 19:41:01,721 DEBUG Loader:182 - done processing result set (1 rows) 19:41:01,721 DEBUG BatcherImpl:173 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:41:01,731 DEBUG SessionFactoryImpl:554 - closing statement 19:41:01,731 DEBUG Loader:195 - total objects hydrated: 1 19:41:01,741 DEBUG SessionImpl:1954 - resolving associations for [test.Group#1 ] 19:41:01,741 DEBUG SessionImpl:2888 - initializing collection [test.Group.persons#1 ] 19:41:01,741 DEBUG BatcherImpl:166 - about to open: 0 open PreparedStatements, 0 open ResultSets 19:41:01,771 DEBUG SessionFactoryImpl:526 - prepared statement get: select tbl_pers0_.person_id as person_id__, tbl_pers0_.person_id as person_id, tbl_pers0_.person_name as person_n2_, tbl_pers0_.group_id as group_id from tbl_person tbl_pers0_ where tbl_pers0_.group_id=? Hibernate: select tbl_pers0_.person_id as person_id__, tbl_pers0_.person_id as person_id, tbl_pers0_.person_name as person_n2_, tbl_pers0_.group_id as group_id from tbl_person tbl_pers0_ where tbl_pers0_.group_id=? 19:41:01,791 DEBUG SessionFactoryImpl:536 - preparing statement 19:41:01,791 DEBUG StringType:44 - binding '1 ' to parameter: 1 19:41:01,811 DEBUG Loader:148 - processing result set 19:41:01,811 DEBUG StringType:65 - returning '11 ' as column: person_id 19:41:01,821 DEBUG Loader:260 - result row: 11 19:41:01,821 DEBUG StringType:65 - returning '11 ' as column: person_id__ 19:41:01,821 DEBUG SessionImpl:1752 - loading [test.Person#11 ] 19:41:01,831 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#11 ] 19:41:01,831 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#11 ] 19:41:01,841 DEBUG StringType:65 - returning '12 ' as column: person_id 19:41:01,841 DEBUG Loader:260 - result row: 12 19:41:01,841 DEBUG StringType:65 - returning '12 ' as column: person_id__ 19:41:01,841 DEBUG SessionImpl:1752 - loading [test.Person#12 ] 19:41:01,851 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#12 ] 19:41:01,851 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#12 ] 19:41:01,861 DEBUG StringType:65 - returning '13 ' as column: person_id 19:41:01,871 DEBUG Loader:260 - result row: 13 19:41:01,881 DEBUG StringType:65 - returning '13 ' as column: person_id__ 19:41:01,881 DEBUG SessionImpl:1752 - loading [test.Person#13 ] 19:41:01,881 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#13 ] 19:41:01,901 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#13 ] 19:41:01,901 DEBUG StringType:65 - returning '14 ' as column: person_id 19:41:01,911 DEBUG Loader:260 - result row: 14 19:41:01,911 DEBUG StringType:65 - returning '14 ' as column: person_id__ 19:41:01,911 DEBUG SessionImpl:1752 - loading [test.Person#14 ] 19:41:01,921 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#14 ] 19:41:01,921 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#14 ] 19:41:01,931 DEBUG StringType:65 - returning '15 ' as column: person_id 19:41:01,931 DEBUG Loader:260 - result row: 15 19:41:01,931 DEBUG StringType:65 - returning '15 ' as column: person_id__ 19:41:01,941 DEBUG SessionImpl:1752 - loading [test.Person#15 ] 19:41:01,941 DEBUG SessionImpl:1843 - attempting to resolve [test.Person#15 ] 19:41:01,951 DEBUG SessionImpl:1858 - resolved object in session cache [test.Person#15 ] 19:41:01,951 DEBUG Loader:182 - done processing result set (5 rows) 19:41:01,951 DEBUG BatcherImpl:173 - done closing: 0 open PreparedStatements, 0 open ResultSets 19:41:01,961 DEBUG SessionFactoryImpl:554 - closing statement 19:41:01,961 DEBUG Loader:195 - total objects hydrated: 0 19:41:01,961 DEBUG SessionImpl:1975 - done materializing entity [test.Group#1 ] 19:41:01,971 DEBUG SessionImpl:1975 - done materializing entity [test.Person#11 ] 19:41:01,991 DEBUG SessionImpl:1954 - resolving associations for [test.Person#12 ] 19:41:01,991 DEBUG SessionImpl:1752 - loading [test.Group#1 ] 19:41:01,991 DEBUG SessionImpl:1843 - attempting to resolve [test.Group#1 ] 19:41:01,991 DEBUG SessionImpl:1858 - resolved object in session cache [test.Group#1 ] 19:41:02,001 DEBUG SessionImpl:1975 - done materializing entity [test.Person#12 ] 19:41:02,001 DEBUG SessionImpl:1954 - resolving associations for [test.Person#13 ] 19:41:02,001 DEBUG SessionImpl:1752 - loading [test.Group#1 ] 19:41:02,011 DEBUG SessionImpl:1843 - attempting to resolve [test.Group#1 ] 19:41:02,011 DEBUG SessionImpl:1858 - resolved object in session cache [test.Group#1 ] 19:41:02,011 DEBUG SessionImpl:1975 - done materializing entity [test.Person#13 ] 19:41:02,021 DEBUG SessionImpl:1954 - resolving associations for [test.Person#14 ] 19:41:02,021 DEBUG SessionImpl:1752 - loading [test.Group#1 ] 19:41:02,021 DEBUG SessionImpl:1843 - attempting to resolve [test.Group#1 ] 19:41:02,021 DEBUG SessionImpl:1858 - resolved object in session cache [test.Group#1 ] 19:41:02,031 DEBUG SessionImpl:1975 - done materializing entity [test.Person#14 ] 19:41:02,031 DEBUG SessionImpl:1954 - resolving associations for [test.Person#15 ] 19:41:02,041 DEBUG SessionImpl:1752 - loading [test.Group#1 ] 19:41:02,041 DEBUG SessionImpl:1843 - attempting to resolve [test.Group#1 ] 19:41:02,041 DEBUG SessionImpl:1858 - resolved object in session cache [test.Group#1 ] 19:41:02,051 DEBUG SessionImpl:1975 - done materializing entity [test.Person#15 ] 19:41:02,051 DEBUG SessionImpl:1975 - done materializing entity [test.Group#1] ---------------------------------------------------------------------------------------------------------------------------------------- If hibernate have a trim() operator when dealing with SQLServerDialect, the problem will be corrected perfectly. --------------------------------------------------------------------- JIRA INFORMATION: This message is automatically generated by JIRA. If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa If you want more information on JIRA, or have a bug to report see: http://www.atlassian.com/software/jira |