Hi all,
I've been using Hibernate for a couple of months now as my persistence provider in Glassfish, and everything's gone well mostly, except for the occasional RollbackException: transaction marked for rollback once in a while.
My problem is, it's very hard to find the root cause of such exception, since Hibernate decides to mark the transaction for rollback but doesn't say why. I was able to find the reason everytime up until now (when trying to persist an entity, an object was found not marked as cascade persist).
But now it fails in a completely different situation and I'm clueless. I'm trying to do a simple select query: the resulting class (Vendedor) has a OneToOne relation to Ente, which in turn has a OneToMany relation to Domicilio. Apparently the error comes up when trying to load the OneToMany relation (even though it's default to FetchType.LAZY).
This is my log
Code:
01:24:08,382 DEBUG SessionImpl:247 - opened session at timestamp: 12374366483
01:24:08,383 DEBUG AbstractEntityManagerImpl:439 - Looking for a JTA transaction to join
01:24:08,384 DEBUG JDBCContext:199 - successfully registered Synchronization
01:24:08,385 DEBUG AbstractBatcher:410 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
01:24:08,386 DEBUG ConnectionManager:444 - opening JDBC connection
01:24:08,387 DEBUG SQL:111 - select vendedor0_.id as id395_, vendedor0_1_.codigo as codigo395_, vendedor0_1_.eliminado as eliminado395_, vendedor0_1_.ente_id as ente5_395_, vendedor0_1_.habilitado as habilitado395_, vendedor0_.oficina_id as oficina2_410_ from Vendedor vendedor0_ inner join Personal vendedor0_1_ on vendedor0_.id=vendedor0_1_.id, Ente ente1_ where vendedor0_1_.ente_id=ente1_.id and vendedor0_1_.eliminado=0 and (upper(ente1_.denominacion) like ?)
Hibernate: select vendedor0_.id as id395_, vendedor0_1_.codigo as codigo395_, vendedor0_1_.eliminado as eliminado395_, vendedor0_1_.ente_id as ente5_395_, vendedor0_1_.habilitado as habilitado395_, vendedor0_.oficina_id as oficina2_410_ from Vendedor vendedor0_ inner join Personal vendedor0_1_ on vendedor0_.id=vendedor0_1_.id, Ente ente1_ where vendedor0_1_.ente_id=ente1_.id and vendedor0_1_.eliminado=0 and (upper(ente1_.denominacion) like ?)
01:24:08,389 DEBUG AbstractBatcher:426 - about to open ResultSet (open ResultSets: 0, globally: 0)
01:24:08,390 DEBUG Loader:1197 - result row: EntityKey[inertial.brokers.ejb.estructura.Vendedor#f95a9003-7849-4632-ba68-e19c79115f03]
01:24:08,391 DEBUG AbstractBatcher:433 - about to close ResultSet (open ResultSets: 1, globally: 1)
01:24:08,392 DEBUG AbstractBatcher:418 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
01:24:08,393 DEBUG ConnectionManager:427 - aggressively releasing JDBC connection
01:24:08,394 DEBUG ConnectionManager:464 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
01:24:08,395 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.estructura.Vendedor#f95a9003-7849-4632-ba68-e19c79115f03]
01:24:08,396 DEBUG Loader:1873 - loading entity: [inertial.brokers.ejb.personas.Ente#77fc17f0-1e30-4b0e-a983-118b83c28056]
01:24:08,398 DEBUG AbstractBatcher:410 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
01:24:08,401 DEBUG ConnectionManager:444 - opening JDBC connection
01:24:08,403 DEBUG SQL:111 - select ente0_.id as id394_3_, ente0_.condicionGanancias as condicio2_394_3_, ente0_.condicionIVA as condicio3_394_3_, ente0_.convenioMultilateral as convenio4_394_3_, ente0_.denominacion as denomina5_394_3_, ente0_.empresa_id as empresa11_394_3_, ente0_.fechaAlta as fechaAlta394_3_, ente0_.fechaBaja as fechaBaja394_3_, ente0_.identificador as identifi8_394_3_, ente0_.mail as mail394_3_, ente0_.persona_id as persona12_394_3_, ente0_.telefono as telefono394_3_, empresa1_.id as id425_0_, empresa1_.actividadSellados as activida2_425_0_, empresa1_.categoriaIngresosBrutos_id as categor15_425_0_, empresa1_.cuit as cuit425_0_, empresa1_.exportador as exportador425_0_, empresa1_.fechaInscripcion as fechaIns5_425_0_, empresa1_.folio as folio425_0_, empresa1_.importador as importador425_0_, empresa1_.nombre as nombre425_0_, empresa1_.notaIngresosBrutos as notaIngr9_425_0_, empresa1_.numero as numero425_0_, empresa1_.numeroIngresosBrutos as numeroI11_425_0_, empresa1_.razonSocial as razonSo12_425_0_, empresa1_.tipoSociedad as tipoSoc13_425_0_, empresa1_.tomo as tomo425_0_, categoriai2_.id as id426_1_, categoriai2_.codigo as codigo426_1_, categoriai2_.eliminada as eliminada426_1_, categoriai2_.nombre as nombre426_1_, persona3_.id as id399_2_, persona3_.apellido as apellido399_2_, persona3_.documento as documento399_2_, persona3_.nacimiento as nacimiento399_2_, persona3_.nombre as nombre399_2_ from Ente ente0_ left outer join Empresa empresa1_ on ente0_.empresa_id=empresa1_.id left outer join CategoriaIngresosBrutos categoriai2_ on empresa1_.categoriaIngresosBrutos_id=categoriai2_.id left outer join Persona persona3_ on ente0_.persona_id=persona3_.id where ente0_.id=?
Hibernate: select ente0_.id as id394_3_, ente0_.condicionGanancias as condicio2_394_3_, ente0_.condicionIVA as condicio3_394_3_, ente0_.convenioMultilateral as convenio4_394_3_, ente0_.denominacion as denomina5_394_3_, ente0_.empresa_id as empresa11_394_3_, ente0_.fechaAlta as fechaAlta394_3_, ente0_.fechaBaja as fechaBaja394_3_, ente0_.identificador as identifi8_394_3_, ente0_.mail as mail394_3_, ente0_.persona_id as persona12_394_3_, ente0_.telefono as telefono394_3_, empresa1_.id as id425_0_, empresa1_.actividadSellados as activida2_425_0_, empresa1_.categoriaIngresosBrutos_id as categor15_425_0_, empresa1_.cuit as cuit425_0_, empresa1_.exportador as exportador425_0_, empresa1_.fechaInscripcion as fechaIns5_425_0_, empresa1_.folio as folio425_0_, empresa1_.importador as importador425_0_, empresa1_.nombre as nombre425_0_, empresa1_.notaIngresosBrutos as notaIngr9_425_0_, empresa1_.numero as numero425_0_, empresa1_.numeroIngresosBrutos as numeroI11_425_0_, empresa1_.razonSocial as razonSo12_425_0_, empresa1_.tipoSociedad as tipoSoc13_425_0_, empresa1_.tomo as tomo425_0_, categoriai2_.id as id426_1_, categoriai2_.codigo as codigo426_1_, categoriai2_.eliminada as eliminada426_1_, categoriai2_.nombre as nombre426_1_, persona3_.id as id399_2_, persona3_.apellido as apellido399_2_, persona3_.documento as documento399_2_, persona3_.nacimiento as nacimiento399_2_, persona3_.nombre as nombre399_2_ from Ente ente0_ left outer join Empresa empresa1_ on ente0_.empresa_id=empresa1_.id left outer join CategoriaIngresosBrutos categoriai2_ on empresa1_.categoriaIngresosBrutos_id=categoriai2_.id left outer join Persona persona3_ on ente0_.persona_id=persona3_.id where ente0_.id=?
01:24:08,443 DEBUG AbstractBatcher:426 - about to open ResultSet (open ResultSets: 0, globally: 0)
01:24:08,445 DEBUG Loader:1197 - result row: null, null, EntityKey[inertial.brokers.ejb.personas.Persona#ef991531-0aa0-4545-8129-3415286eb9d6], EntityKey[inertial.brokers.ejb.personas.Ente#77fc17f0-1e30-4b0e-a983-118b83c28056]
01:24:08,446 DEBUG AbstractBatcher:433 - about to close ResultSet (open ResultSets: 1, globally: 1)
01:24:08,448 DEBUG AbstractBatcher:418 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
01:24:08,448 DEBUG ConnectionManager:427 - aggressively releasing JDBC connection
01:24:08,449 DEBUG ConnectionManager:464 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
01:24:08,450 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.personas.Persona#ef991531-0aa0-4545-8129-3415286eb9d6]
01:24:08,452 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.personas.Persona#ef991531-0aa0-4545-8129-3415286eb9d6]
01:24:08,453 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.personas.Ente#77fc17f0-1e30-4b0e-a983-118b83c28056]
01:24:08,456 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.personas.Ente#77fc17f0-1e30-4b0e-a983-118b83c28056]
01:24:08,457 DEBUG Loader:1904 - done entity load
01:24:08,469 DEBUG Loader:1873 - loading entity: [inertial.brokers.ejb.estructura.Oficina#0a263907-e5af-4c68-b8c3-9fb292baa116]
01:24:08,470 DEBUG AbstractBatcher:410 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
01:24:08,472 DEBUG ConnectionManager:444 - opening JDBC connection
01:24:08,473 DEBUG SQL:111 - select oficina0_.id as id397_6_, oficina0_.codigo as codigo397_6_, oficina0_.domicilio_id as domicilio5_397_6_, oficina0_.eliminada as eliminada397_6_, oficina0_.nombre as nombre397_6_, oficina0_.zona_id as zona6_397_6_, domicilio1_.id as id415_0_, domicilio1_.barrio as barrio415_0_, domicilio1_.calle as calle415_0_, domicilio1_.celular as celular415_0_, domicilio1_.departamento as departam5_415_0_, domicilio1_.fax as fax415_0_, domicilio1_.kilometro as kilometro415_0_, domicilio1_.localidad_id as localidad14_415_0_, domicilio1_.numero as numero415_0_, domicilio1_.observaciones as observac9_415_0_, domicilio1_.piso as piso415_0_, domicilio1_.ruta as ruta415_0_, domicilio1_.telefono as telefono415_0_, domicilio1_.tipo as tipo415_0_, localidad2_.id as id422_1_, localidad2_.codigo as codigo422_1_, localidad2_.codigoPostal_id as codigoPo4_422_1_, localidad2_.nombre as nombre422_1_, localidad2_.provincia_id as provincia5_422_1_, codigopost3_.id as id391_2_, codigopost3_.codigo as codigo391_2_, codigopost3_.codigoNumero as codigoNu3_391_2_, provincia4_.id as id419_3_, provincia4_.codigo as codigo419_3_, provincia4_.nombre as nombre419_3_, zona5_.id as id409_4_, zona5_.codigo as codigo409_4_, zona5_.descripcion as descripc3_409_4_, zona5_.eliminada as eliminada409_4_, zona5_.nombre as nombre409_4_, zona5_.organizacion_id as organiza6_409_4_, organizaci6_.id as id404_5_, organizaci6_.codigo as codigo404_5_, organizaci6_.detalles as detalles404_5_, organizaci6_.eliminada as eliminada404_5_, organizaci6_.nombre as nombre404_5_ from Oficina oficina0_ left outer join Domicilio domicilio1_ on oficina0_.domicilio_id=domicilio1_.id left outer join Localidad localidad2_ on domicilio1_.localidad_id=localidad2_.id left outer join CodigoPostal codigopost3_ on localidad2_.codigoPostal_id=codigopost3_.id left outer join Provincia provincia4_ on localidad2_.provincia_id=provincia4_.id left outer join Zona zona5_ on oficina0_.zona_id=zona5_.id left outer join Organizacion organizaci6_ on zona5_.organizacion_id=organizaci6_.id where oficina0_.id=?
Hibernate: select oficina0_.id as id397_6_, oficina0_.codigo as codigo397_6_, oficina0_.domicilio_id as domicilio5_397_6_, oficina0_.eliminada as eliminada397_6_, oficina0_.nombre as nombre397_6_, oficina0_.zona_id as zona6_397_6_, domicilio1_.id as id415_0_, domicilio1_.barrio as barrio415_0_, domicilio1_.calle as calle415_0_, domicilio1_.celular as celular415_0_, domicilio1_.departamento as departam5_415_0_, domicilio1_.fax as fax415_0_, domicilio1_.kilometro as kilometro415_0_, domicilio1_.localidad_id as localidad14_415_0_, domicilio1_.numero as numero415_0_, domicilio1_.observaciones as observac9_415_0_, domicilio1_.piso as piso415_0_, domicilio1_.ruta as ruta415_0_, domicilio1_.telefono as telefono415_0_, domicilio1_.tipo as tipo415_0_, localidad2_.id as id422_1_, localidad2_.codigo as codigo422_1_, localidad2_.codigoPostal_id as codigoPo4_422_1_, localidad2_.nombre as nombre422_1_, localidad2_.provincia_id as provincia5_422_1_, codigopost3_.id as id391_2_, codigopost3_.codigo as codigo391_2_, codigopost3_.codigoNumero as codigoNu3_391_2_, provincia4_.id as id419_3_, provincia4_.codigo as codigo419_3_, provincia4_.nombre as nombre419_3_, zona5_.id as id409_4_, zona5_.codigo as codigo409_4_, zona5_.descripcion as descripc3_409_4_, zona5_.eliminada as eliminada409_4_, zona5_.nombre as nombre409_4_, zona5_.organizacion_id as organiza6_409_4_, organizaci6_.id as id404_5_, organizaci6_.codigo as codigo404_5_, organizaci6_.detalles as detalles404_5_, organizaci6_.eliminada as eliminada404_5_, organizaci6_.nombre as nombre404_5_ from Oficina oficina0_ left outer join Domicilio domicilio1_ on oficina0_.domicilio_id=domicilio1_.id left outer join Localidad localidad2_ on domicilio1_.localidad_id=localidad2_.id left outer join CodigoPostal codigopost3_ on localidad2_.codigoPostal_id=codigopost3_.id left outer join Provincia provincia4_ on localidad2_.provincia_id=provincia4_.id left outer join Zona zona5_ on oficina0_.zona_id=zona5_.id left outer join Organizacion organizaci6_ on zona5_.organizacion_id=organizaci6_.id where oficina0_.id=?
01:24:08,552 DEBUG AbstractBatcher:426 - about to open ResultSet (open ResultSets: 0, globally: 0)
01:24:08,553 DEBUG Loader:1197 - result row: EntityKey[inertial.brokers.ejb.personas.Domicilio#aeee2dd5-44d4-4c87-8353-f14a0a781b3b], EntityKey[inertial.brokers.ejb.ubicaciones.Localidad#e4174294-39ac-466d-b3f8-ae25732c1c6b], null, EntityKey[inertial.brokers.ejb.ubicaciones.Provincia#d9a328a1-cf3b-4980-b096-4be01c71fb11], EntityKey[inertial.brokers.ejb.estructura.Zona#de8fe285-f62c-4fbc-aacf-fd7d722e1481], EntityKey[inertial.brokers.ejb.estructura.Organizacion#4f48f5af-918a-4c1a-a5b0-da96f3888280], EntityKey[inertial.brokers.ejb.estructura.Oficina#0a263907-e5af-4c68-b8c3-9fb292baa116]
01:24:08,555 DEBUG AbstractBatcher:433 - about to close ResultSet (open ResultSets: 1, globally: 1)
01:24:08,556 DEBUG AbstractBatcher:418 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
01:24:08,557 DEBUG ConnectionManager:427 - aggressively releasing JDBC connection
01:24:08,558 DEBUG ConnectionManager:464 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
01:24:08,559 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.personas.Domicilio#aeee2dd5-44d4-4c87-8353-f14a0a781b3b]
01:24:08,561 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.personas.Domicilio#aeee2dd5-44d4-4c87-8353-f14a0a781b3b]
01:24:08,563 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.ubicaciones.Localidad#e4174294-39ac-466d-b3f8-ae25732c1c6b]
01:24:08,565 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.ubicaciones.Localidad#e4174294-39ac-466d-b3f8-ae25732c1c6b]
01:24:08,566 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.ubicaciones.Provincia#d9a328a1-cf3b-4980-b096-4be01c71fb11]
01:24:08,567 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.ubicaciones.Provincia#d9a328a1-cf3b-4980-b096-4be01c71fb11]
01:24:08,568 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.estructura.Zona#de8fe285-f62c-4fbc-aacf-fd7d722e1481]
01:24:08,569 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.estructura.Zona#de8fe285-f62c-4fbc-aacf-fd7d722e1481]
01:24:08,570 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.estructura.Organizacion#4f48f5af-918a-4c1a-a5b0-da96f3888280]
01:24:08,571 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.estructura.Organizacion#4f48f5af-918a-4c1a-a5b0-da96f3888280]
01:24:08,572 DEBUG TwoPhaseLoad:130 - resolving associations for [inertial.brokers.ejb.estructura.Oficina#0a263907-e5af-4c68-b8c3-9fb292baa116]
01:24:08,573 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.estructura.Oficina#0a263907-e5af-4c68-b8c3-9fb292baa116]
01:24:08,574 DEBUG Loader:1904 - done entity load
01:24:08,575 DEBUG TwoPhaseLoad:226 - done materializing entity [inertial.brokers.ejb.estructura.Vendedor#f95a9003-7849-4632-ba68-e19c79115f03]
01:24:08,576 DEBUG StatefulPersistenceContext:860 - initializing non-lazy collections
01:24:08,577 DEBUG AbstractFlushingEventListener:134 - processing flush-time cascades
01:24:08,578 DEBUG AbstractFlushingEventListener:177 - dirty checking collections
01:24:08,620 DEBUG Collections:199 - Collection found: [inertial.brokers.ejb.personas.Ente.domicilios#77fc17f0-1e30-4b0e-a983-118b83c28056], was: [inertial.brokers.ejb.personas.Ente.domicilios#77fc17f0-1e30-4b0e-a983-118b83c28056] (uninitialized)
01:24:08,621 DEBUG AbstractEntityManagerImpl:406 - mark transaction for rollback
EJB5018: An exception was thrown during an ejb invocation on [ControlPersonalBean]
javax.ejb.EJBException: Transaction aborted; nested exception is: javax.transaction.RollbackException: Transaction marked for rollback.
javax.transaction.RollbackException: Transaction marked for rollback.
at com.sun.enterprise.distributedtx.J2EETransaction.commit(J2EETransaction.java:449)
at com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.commit(J2EETransactionManagerOpt.java:371)
at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:3817)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3596)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1379)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1316)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:205)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:83)
at $Proxy109.buscarVendedores(Unknown Source)
..(cut out the very long trace here)...
Caused by: javax.ejb.EJBException: Transaction aborted; nested exception is: javax.transaction.RollbackException: Transaction marked for rollback.
at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:3823)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3596)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1379)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1316)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:205)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:83)
at $Proxy109.buscarVendedores(Unknown Source)
at inertial.brokers.web.produccion.CotizarVehiculoBean.buscarVendedores(CotizarVehiculoBean.java:86)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.sun.el.parser.AstValue.invoke(AstValue.java:187)
at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:297)
at com.sun.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:68)
... 47 more
As I said, from inspecting the log and Hibernate source, it appears the collection is being loaded, even though it is NOT marked as EAGER and it is also empty!
As a test, I tried calling the same method from a remote, standalone Swing app-client and the exception is not thrown, but the query returns an empty List (which is not the case with the web client, as you can see the -only- Vendedor matching instance being found in the log). Weird.
I'd like to find out the real reason why the tx is marked for rollback, so I can correct any errors in my code, because it seems to be OK and I'm done with guessing already.
Thanks!
Login
FAQ
Search