Announcement Announcement Module
Collapse
No announcement yet.
Why are new sessions created with OpenSessionInViewFilter? Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • Why are new sessions created with OpenSessionInViewFilter?

    Hi all,

    I'm really stuck. I'm using hibernate 2.1.8 and I am getting "Could not
    initialize proxy - the owning Session was closed at the Action level - works fine at the service level. I've been led to believe that somehow my DAO's, Actions and/or forms are cached and therefore new sessions are automatically created.

    OK, so I have a daoContext.xml which has thing like:

    <bean id="activityDAO" class="com.siemens.swa.dao.ActivityDAOImpl">
    <property name="sessionFactory"><ref bean="mySessionFactory"/></property>
    </bean>
    <bean id="basicDAO" class="com.siemens.swa.dao.BasicDAOImpl">
    <property name="sessionFactory"><ref bean="mySessionFactory"/></property>
    </bean>

    And I have a actionContext.xml with things like:

    <bean name="/TrackingExecutionOperation" class="com.siemens.swa.action.TrackingExecutionOpe rationAction">
    <property name="activityTrackerService"><ref bean="activityTrackerService"/></property>
    <property name="basicService"><ref bean="basicService"/></property>
    <property name="appointmentSchedulerService"><ref bean="appointmentSchedulerService"/></property>
    </bean>

    And some transactions defined in serviceContext.xml:


    <bean id="activityTrackerService" class="org.springframework.transaction.interceptor .TransactionProxyFactoryBean">
    <property name="transactionManager"><ref bean="myTransactionManager"/></property>
    <property name="target"><ref bean="ActivityTrackerServiceImpl"/></property>
    <property name="preInterceptors">
    <list>
    <ref bean="SpringLogDebugReturnAspect"/>
    <ref bean="SpringLogErroAspect"/>
    <ref bean="SpringLogInfoDebugAspect"/>
    </list>
    </property>
    <property name="transactionAttributes">
    <props>
    <prop key="performUpdateOrCreateTasks">PROPAGATION_REQUI RED</prop>
    <prop key="update*">PROPAGATION_REQUIRED</prop>
    <prop key="create*">PROPAGATION_REQUIRED</prop>
    <prop key="assign*">PROPAGATION_REQUIRED</prop>
    <prop key="reassign*">PROPAGATION_REQUIRED</prop>
    <prop key="remove*">PROPAGATION_REQUIRED</prop>
    <prop key="find*">PROPAGATION_REQUIRED,readOnly</prop>
    </props>
    </property>
    </bean>
    <bean id="ActivityTrackerServiceImpl" class="com.siemens.swa.service.ActivityTrackerServ iceImpl">
    <property name="activityDAO"><ref bean="activityDAO"/></property>
    <property name="basicDAO"><ref bean="basicDAO"/></property>
    <property name="technicianDAO"><ref bean="techDAO"/></property>
    <property name="interruptionDAO"><ref bean="interruptionDAO"/></property>
    <property name="appointmentSchedulerService"><ref bean="appointmentSchedulerService"/></property>
    <property name="technicianTrackingExecutionDAO"><ref bean="technicianTrackingExecutionDAO"/></property>
    </bean>

    <bean id="basicService" class="org.springframework.transaction.interceptor .TransactionProxyFactoryBean">
    <property name="transactionManager"><ref bean="myTransactionManager"/></property>
    <property name="target"><ref bean="basicServ"/></property>
    <property name="transactionAttributes">
    <props>
    <prop key="find*">PROPAGATION_REQUIRED,readOnly</prop>
    <prop key="create">PROPAGATION_REQUIRED</prop>
    <prop key="update">PROPAGATION_REQUIRED</prop>
    <prop key="remove">PROPAGATION_REQUIRED</prop>
    </props>
    </property>
    </bean>


    <bean id="basicServ" class="com.siemens.swa.service.BasicServiceImpl">
    <property name="basicDAO"><ref bean="basicDAO"/></property>
    </bean>

    I have a filter configured like:

    <filter>
    <filter-name>hibernate</filter-name>
    <filter-class>com.siemens.swa.util.persistence.HibernateSe ssionFilter</filter-class>
    <init-param>
    <param-name>singleSession</param-name>
    <param-value>true</param-value>
    </init-param>
    <init-param>
    <param-name>sessionFactoryBeanName</param-name>
    <param-value>mySessionFactory</param-value>
    </init-param>
    </filter>

    <filter-mapping>
    <filter-name>hibernate</filter-name>
    <url-pattern>*.do</url-pattern>
    </filter-mapping>

    <filter-mapping>
    <filter-name>hibernate</filter-name>
    <url-pattern>*.jsp</url-pattern>
    </filter-mapping>


    With a class:

    public class HibernateSessionFilter extends OpenSessionInViewFilter
    implements Filter, Logable {


    protected Session getSession(SessionFactory sessionFactory)
    throws DataAccessResourceFailureException {

    Session session = SessionFactoryUtils.getSession(sessionFactory, true);
    session.setFlushMode(FlushMode.AUTO);
    System.out.println("SessionFactoryBeanName: " + getSessionFactoryBeanName());
    System.out.println("AlreadyFilteredAttributeName() : " + getAlreadyFilteredAttributeName());
    return session;
    }

    protected void closeSession(Session session, SessionFactory sessionFactory) {

    if (session != null && session.isOpen() && session.isConnected()) {
    try {
    session.flush();
    } catch (HibernateException e) {
    throw new RuntimeException("Failed to flush session before close: " + e.getMessage(), e);
    }
    }
    super.closeSession(session, sessionFactory);
    }

    ...
    }

    And a struts config :

    <plug-in className="org.springframework.web.struts.ContextL oaderPlugIn">
    <set-property property="contextConfigLocation"
    value=" /WEB-INF/applicationContext.xml /WEB-INF/actionContext.xml /WEB-INF/serviceContext.xml /WEB-INF/daoContext.xml"/>
    </plug-in>

    So finally, this is happening in my logs. Its long, but its on the HTTP request that throws and its the only real way to understand whats going on. Its throwing in TrackingExecutionOperation Action, as referenced in the above config and stack trace:

    2005-05-13 11:35:19,758
    [org.apache.catalina.core.StandardWrapper] -
    Returning non-STM instance
    2005-05-13 11:35:19,758
    [org.springframework.beans.factory.support.DefaultL istableBeanFactory]
    - Returning cached instance of singleton bean
    'mySessionFactory'
    2005-05-13 11:35:19,758
    [org.springframework.beans.factory.support.DefaultL istableBeanFactory]
    - Bean with name 'mySessionFactory' is a factory bean
    2005-05-13 11:35:19,759
    [org.springframework.orm.hibernate.SessionFactoryUt ils]
    - Opening Hibernate session
    2005-05-13 11:35:19,759
    [net.sf.hibernate.impl.SessionImpl] - opened session
    2005-05-13 11:35:19,759
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Bound value
    [org.springframework.orm.hibernate.SessionHolder@70 8aff]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@111f9b] to
    thread [http-8080-Processor23]
    2005-05-13 11:35:19,759
    [org.apache.struts.util.ModuleUtils] - Get module name
    for path /TrackingExecutionOperation.do
    2005-05-13 11:35:19,759
    [org.apache.struts.util.ModuleUtils] - Module name
    found: default
    2005-05-13 11:35:19,759
    [org.apache.struts.action.RequestProcessor] -
    Processing a 'GET' for path
    '/TrackingExecutionOperation'
    2005-05-13 11:35:19,759
    [org.apache.struts.util.RequestUtils] - Looking for
    ActionForm bean instance in scope 'request' under
    attribute key 'trackingExecutionForm'
    2005-05-13 11:35:19,764
    [org.apache.struts.util.RequestUtils] - Creating new
    ActionForm instance of type
    'com.siemens.swa.form.TrackingExecutionForm'
    2005-05-13 11:35:19,764
    [org.apache.struts.util.RequestUtils] - -->
    com.siemens.swa.form.TrackingExecutionForm@b58e73
    2005-05-13 11:35:19,764
    [org.apache.struts.action.RequestProcessor] - Storing
    ActionForm bean instance in scope 'request' under
    attribute key 'trackingExecutionForm'
    2005-05-13 11:35:19,764
    [org.apache.struts.action.RequestProcessor] -
    Populating bean properties from this request
    2005-05-13 11:35:19,764
    [org.apache.commons.beanutils.BeanUtils] -
    BeanUtils.populate(com.siemens.swa.form.TrackingEx ecutionForm@b58e73,
    {action=[Ljava.lang.String;@19b3d1b,
    activityId=[Ljava.lang.String;@c8c3b8})
    2005-05-13 11:35:19,765
    [org.apache.commons.beanutils.BeanUtils] -
    setProperty(com.siemens.swa.form.TrackingExecution Form@b58e73,
    action, [openMainPage])
    2005-05-13 11:35:19,776
    [org.apache.commons.beanutils.BeanUtils] -
    setProperty(com.siemens.swa.form.TrackingExecution Form@b58e73,
    activityId, [18996])
    2005-05-13 11:35:19,776
    [org.apache.commons.beanutils.ConvertUtils] - Convert
    string '18996' to class 'java.lang.String'
    2005-05-13 11:35:19,776
    [org.apache.commons.beanutils.ConvertUtils] - Using
    converter
    org.apache.commons.beanutils.converters.StringConv erter@92666

    2005-05-13 11:35:19,776
    [org.apache.struts.action.RequestProcessor] - Looking
    for Action instance for class
    org.springframework.web.struts.DelegatingActionPro xy
    2005-05-13 11:35:19,776
    [org.apache.struts.action.RequestProcessor] -
    Returning existing Action instance
    2005-05-13 11:35:19,776
    [org.springframework.web.struts.DelegatingActionUti ls]
    - DelegatingActionProxy with mapping path
    '/TrackingExecutionOperation' and module prefix ''
    delegating to Spring bean with name
    [/TrackingExecutionOperation]
    2005-05-13 11:35:19,776
    [org.springframework.beans.factory.support.DefaultL istableBeanFactory]
    - Returning cached instance of singleton bean
    '/TrackingExecutionOperation'
    2005-05-13 11:35:23,796
    [org.springframework.transaction.interceptor.Transa ctionInterceptor]
    - Getting transaction for method 'findById' in class
    [com.siemens.swa.service.BasicService]
    2005-05-13 11:35:23,797
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Using transaction object
    [org.springframework.orm.hibernate.HibernateTransac tionManager$HibernateTransactionObject@177d583]
    2005-05-13 11:35:23,797
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Creating new transaction
    2005-05-13 11:35:23,797
    [org.springframework.orm.hibernate.SessionFactoryUt ils]
    - Opening Hibernate session
    2005-05-13 11:35:23,797
    [net.sf.hibernate.impl.SessionImpl] - opened session
    2005-05-13 11:35:23,797
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Opened new session
    [net.sf.hibernate.impl.SessionImpl@628e42] for
    Hibernate transaction
    2005-05-13 11:35:23,841
    [org.springframework.jdbc.datasource.DataSourceUtil s]
    - Setting JDBC connection
    [com.mysql.jdbc.Connection@69cfe0] read-only
    2005-05-13 11:35:23,841
    [net.sf.hibernate.transaction.JDBCTransaction] - begin
    2005-05-13 11:35:23,842
    [net.sf.hibernate.transaction.JDBCTransaction] -
    current autocommit status:true
    2005-05-13 11:35:23,842
    [net.sf.hibernate.transaction.JDBCTransaction] -
    disabling autocommit
    2005-05-13 11:35:23,842
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Exposing Hibernate transaction as JDBC transaction
    [com.mysql.jdbc.Connection@69cfe0]
    2005-05-13 11:35:23,842
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Bound value
    [org.springframework.jdbc.datasource.ConnectionHold er@ceb8e2]
    for key
    [com.mysql.jdbc.jdbc2.optional.MysqlDataSource@d86c 58]
    to thread [http-8080-Processor23]
    2005-05-13 11:35:23,842
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Bound value
    [org.springframework.orm.hibernate.SessionHolder@1c c3436]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103] to
    thread [http-8080-Processor23]
    2005-05-13 11:35:23,843
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Initializing transaction synchronization
    2005-05-13 11:35:24,606
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@1c c3436]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:25,210
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@1c c3436]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:25,213
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:25,214
    [net.sf.hibernate.impl.SessionImpl] - attempting to
    resolve [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:25,214
    [net.sf.hibernate.impl.SessionImpl] - object not
    resolved in any cache
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:25,214
    [net.sf.hibernate.persister.EntityPersister] -
    Materializing entity:
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:25,214
    [net.sf.hibernate.impl.BatcherImpl] - about to open: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:25,214 [net.sf.hibernate.SQL] -
    select activity0_.ACTIVITY_ID as ACTIVITY1_0_,
    activity0_.equipment_id as equipmen2_0_,
    activity0_.act_velox_info_id as act_velo3_0_,
    activity0_.act_exec_id as act_exec4_0_,
    activity0_.promise_date as promise_5_0_,
    activity0_.promise_time as promise_6_0_,
    activity0_.promise_end_date as promise_7_0_,
    activity0_.promise_end_time as promise_8_0_,
    activity0_.open_checklist as open_che9_0_,
    activity0_.ACT_SCH_ID as ACT_SCH_ID0_,
    activity0_.activity_num as activit11_0_,
    activity0_.state as state0_, activity0_.type as
    type0_, activity0_.ACT_PRIORITY_ID as ACT_PRI14_0_,
    activity0_.TECHN_AREA_ID as TECHN_A15_0_,
    activity0_.INFORMER_ID as INFORME16_0_,
    activity0_.target_id as target_id0_,
    activity0_.LOCAL_INFO_ID as LOCAL_I18_0_,
    activity0_.ACT_EQUIP_INFO_ID as ACT_EQU19_0_,
    activity0_.assoc_doc as assoc_doc0_,
    activity0_.free_desc as free_desc0_,
    activity0_.TECHN_AREA_RAMIF_ID as TECHN_A22_0_,
    activity0_.ACT_CLIENT_INFO_ID as ACT_CLI23_0_,
    activity0_.initial_interrupt_date as initial24_0_,
    activity0_.initial_interrupt_time as initial25_0_,
    activity0_.EXTERNAL_INFO_ID as EXTERNA26_0_,
    activity0_.CATEGORY_ID as CATEGOR27_0_,
    activity0_.CORRETIVE_INFO_ID as CORRETI28_0_,
    activity0_.RESERVER_ID as RESERVE29_0_,
    activity0_.RESERVED as RESERVED0_ from ACTIVITY
    activity0_ where activity0_.ACTIVITY_ID=?
    2005-05-13 11:35:25,249
    [net.sf.hibernate.impl.BatcherImpl] - preparing
    statement
    2005-05-13 11:35:25,250
    [net.sf.hibernate.type.LongType] - binding '18996' to
    parameter: 1
    2005-05-13 11:35:25,251
    [net.sf.hibernate.loader.Loader] - processing result
    set
    2005-05-13 11:35:25,251
    [net.sf.hibernate.loader.Loader] - result row: 18996
    2005-05-13 11:35:25,251
    [net.sf.hibernate.loader.Loader] - Initializing object
    from ResultSet: 18996
    2005-05-13 11:35:25,252
    [net.sf.hibernate.loader.Loader] - Hydrating entity:
    com.siemens.swa.domain.Activity#18996
    2005-05-13 11:35:25,256
    [net.sf.hibernate.type.LongType] - returning null as
    column: equipmen2_0_
    2005-05-13 11:35:25,256
    [net.sf.hibernate.type.LongType] - returning null as
    column: act_velo3_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.LongType] - returning '35' as
    column: act_exec4_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.DateType] - returning null as
    column: promise_5_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.TimeType] - returning null as
    column: promise_6_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.TimestampType] - returning null
    as column: promise_7_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.TimeType] - returning null as
    column: promise_8_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.BooleanType] - returning 'true'
    as column: open_che9_0_
    2005-05-13 11:35:25,257
    [net.sf.hibernate.type.LongType] - returning null as
    column: ACT_SCH_ID0_
    2005-05-13 11:35:25,258
    [net.sf.hibernate.type.StringType] - returning
    'COR18996' as column: activit11_0_
    2005-05-13 11:35:25,258
    [net.sf.hibernate.type.LongType] - returning '3' as
    column: ACT_PRI14_0_
    2005-05-13 11:35:25,258
    [net.sf.hibernate.type.LongType] - returning '5' as
    column: TECHN_A15_0_
    2005-05-13 11:35:25,259
    [net.sf.hibernate.type.LongType] - returning '11' as
    column: INFORME16_0_
    2005-05-13 11:35:25,259
    [net.sf.hibernate.type.LongType] - returning '11' as
    column: LOCAL_I18_0_
    2005-05-13 11:35:25,259
    [net.sf.hibernate.type.LongType] - returning '9' as
    column: ACT_EQU19_0_
    2005-05-13 11:35:25,259
    [net.sf.hibernate.type.StringType] - returning 'doc'
    as column: assoc_doc0_
    2005-05-13 11:35:25,259
    [net.sf.hibernate.type.StringType] - returning 'Bla'
    as column: free_desc0_
    2005-05-13 11:35:25,260
    [net.sf.hibernate.type.LongType] - returning '1' as
    column: TECHN_A22_0_
    2005-05-13 11:35:25,260
    [net.sf.hibernate.type.LongType] - returning null as
    column: ACT_CLI23_0_
    2005-05-13 11:35:25,261
    [net.sf.hibernate.type.TimestampType] - returning
    '2005-04-16 00:00:00' as column: initial24_0_
    2005-05-13 11:35:25,263
    [net.sf.hibernate.type.TimeType] - returning
    '11:00:00' as column: initial25_0_
    2005-05-13 11:35:25,264
    [net.sf.hibernate.type.LongType] - returning '5' as
    column: EXTERNA26_0_
    2005-05-13 11:35:25,264
    [net.sf.hibernate.type.LongType] - returning '1' as
    column: CATEGOR27_0_
    2005-05-13 11:35:25,264
    [net.sf.hibernate.type.LongType] - returning '5' as
    column: CORRETI28_0_
    2005-05-13 11:35:25,264
    [net.sf.hibernate.type.LongType] - returning '484' as
    column: RESERVE29_0_
    2005-05-13 11:35:25,264
    [net.sf.hibernate.type.BooleanType] - returning 'true'
    as column: RESERVED0_
    2005-05-13 11:35:25,264
    [net.sf.hibernate.loader.Loader] - done processing
    result set (1 rows)
    2005-05-13 11:35:25,264
    [net.sf.hibernate.impl.BatcherImpl] - done closing: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:25,265
    [net.sf.hibernate.impl.BatcherImpl] - closing
    statement
    2005-05-13 11:35:25,265
    [net.sf.hibernate.loader.Loader] - total objects
    hydrated: 1
    2005-05-13 11:35:25,265
    [net.sf.hibernate.impl.SessionImpl] - resolving
    associations for
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:25,265
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityExecution#35]
    2005-05-13 11:35:25,266
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityPriority#3]
    2005-05-13 11:35:25,266
    [net.sf.hibernate.impl.SessionImpl] - creating
    collection
    wrapper:[com.siemens.swa.domain.Activity.preventiveChecklis t#18996]
    2005-05-13 11:35:25,266
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.TechniqueArea#5]
    2005-05-13 11:35:25,266
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.Informer#11]
    2005-05-13 11:35:25,266
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityLocalInfo#11]
    2005-05-13 11:35:25,267
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityEquipmentInfo#9]
    2005-05-13 11:35:25,267
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.TechniqueAreaRamification#1]
    2005-05-13 11:35:25,267
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ExternalInfo#5]
    2005-05-13 11:35:25,267
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityCategory#1]
    2005-05-13 11:35:25,267
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.CorretiveInfo#5]
    2005-05-13 11:35:25,268
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.User#484]
    2005-05-13 11:35:25,268
    [net.sf.hibernate.impl.SessionImpl] - creating
    collection
    wrapper:[com.siemens.swa.domain.Activity.technicians#18996]
    2005-05-13 11:35:25,268
    [net.sf.hibernate.impl.SessionImpl] - done
    materializing entity
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:25,268
    [net.sf.hibernate.impl.SessionImpl] - initializing
    non-lazy collections
    2005-05-13 11:35:25,268
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@1c c3436]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:25,268
    [org.springframework.transaction.interceptor.Transa ctionInterceptor]
    - Invoking commit for transaction on method 'findById'
    in class [com.siemens.swa.service.BasicService]
    2005-05-13 11:35:25,268
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Triggering beforeCommit synchronization
    2005-05-13 11:35:25,269

    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Triggering beforeCompletion synchronization
    2005-05-13 11:35:25,269
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Initiating transaction commit
    2005-05-13 11:35:25,269
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Committing Hibernate transaction on session
    [net.sf.hibernate.impl.SessionImpl@628e42]
    2005-05-13 11:35:25,269
    [net.sf.hibernate.transaction.JDBCTransaction] -
    commit
    2005-05-13 11:35:25,269
    [net.sf.hibernate.impl.SessionImpl] - transaction
    completion
    2005-05-13 11:35:25,269
    [net.sf.hibernate.transaction.JDBCTransaction] -
    re-enabling autocommit
    2005-05-13 11:35:25,270
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Triggering afterCompletion synchronization
    2005-05-13 11:35:25,270
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Clearing transaction synchronization
    2005-05-13 11:35:25,270
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Removed value
    [org.springframework.orm.hibernate.SessionHolder@1c c3436]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103] from
    thread [http-8080-Processor23]
    2005-05-13 11:35:25,270
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Removed value
    [org.springframework.jdbc.datasource.ConnectionHold er@ceb8e2]
    for key
    [com.mysql.jdbc.jdbc2.optional.MysqlDataSource@d86c 58]
    from thread [http-8080-Processor23]
    2005-05-13 11:35:25,270
    [org.springframework.jdbc.datasource.DataSourceUtil s]
    - Resetting read-only flag of connection
    [com.mysql.jdbc.Connection@69cfe0]
    2005-05-13 11:35:25,270
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Closing Hibernate session
    [net.sf.hibernate.impl.SessionImpl@628e42] after
    transaction
    2005-05-13 11:35:25,270
    [org.springframework.orm.hibernate.SessionFactoryUt ils]
    - Closing Hibernate session
    2005-05-13 11:35:25,270
    [net.sf.hibernate.impl.SessionImpl] - closing session
    2005-05-13 11:35:25,270
    [net.sf.hibernate.impl.SessionImpl] - disconnecting
    session
    2005-05-13 11:35:25,270
    [net.sf.hibernate.impl.SessionImpl] - transaction
    completion
    2005-05-13 11:35:26,131
    [org.springframework.aop.framework.adapter.ThrowsAd viceInterceptor]
    - Found exception handler method [public void
    com.siemens.swa.util.log.SpringLogErroAspect.after Throwing(java.lang.reflect.Method,java.lang.Object[],java.lang.Object,java.lang.Exception)
    throws java.lang.Exception]
    2005-05-13 11:35:26,131
    [org.springframework.transaction.interceptor.Transa ctionInterceptor]
    - Getting transaction for method 'reserveActivity' in
    class
    [com.siemens.swa.service.AppointmentSchedulerServic e]
    2005-05-13 11:35:26,132
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Using transaction object
    [org.springframework.orm.hibernate.HibernateTransac tionManager$HibernateTransactionObject@a3c177]
    2005-05-13 11:35:26,132
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Creating new transaction
    2005-05-13 11:35:26,132
    [org.springframework.orm.hibernate.SessionFactoryUt ils]
    - Opening Hibernate session
    2005-05-13 11:35:26,132
    [net.sf.hibernate.impl.SessionImpl] - opened session
    2005-05-13 11:35:26,132
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Opened new session
    [net.sf.hibernate.impl.SessionImpl@f2794a] for
    Hibernate transaction
    2005-05-13 11:35:26,189
    [net.sf.hibernate.transaction.JDBCTransaction] - begin
    2005-05-13 11:35:26,189
    [net.sf.hibernate.transaction.JDBCTransaction] -
    current autocommit status:true
    2005-05-13 11:35:26,189
    [net.sf.hibernate.transaction.JDBCTransaction] -
    disabling autocommit
    2005-05-13 11:35:26,189
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Exposing Hibernate transaction as JDBC transaction
    [com.mysql.jdbc.Connection@fcfd10]
    2005-05-13 11:35:26,189
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Bound value
    [org.springframework.jdbc.datasource.ConnectionHold er@14a3347]
    for key
    [com.mysql.jdbc.jdbc2.optional.MysqlDataSource@d86c 58]
    to thread [http-8080-Processor23]
    2005-05-13 11:35:26,189
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Bound value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103] to
    thread [http-8080-Processor23]
    2005-05-13 11:35:26,190
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Initializing transaction synchronization
    2005-05-13 11:35:26,190
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,190
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:26,190
    [net.sf.hibernate.impl.SessionImpl] - attempting to
    resolve [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:26,190
    [net.sf.hibernate.impl.SessionImpl] - object not
    resolved in any cache
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:26,190
    [net.sf.hibernate.persister.EntityPersister] -
    Materializing entity:
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:26,190
    [net.sf.hibernate.impl.BatcherImpl] - about to open: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:26,190 [net.sf.hibernate.SQL] -
    select activity0_.ACTIVITY_ID as ACTIVITY1_0_,
    activity0_.equipment_id as equipmen2_0_,
    activity0_.act_velox_info_id as act_velo3_0_,
    activity0_.act_exec_id as act_exec4_0_,
    activity0_.promise_date as promise_5_0_,
    activity0_.promise_time as promise_6_0_,
    activity0_.promise_end_date as promise_7_0_,
    activity0_.promise_end_time as promise_8_0_,
    activity0_.open_checklist as open_che9_0_,
    activity0_.ACT_SCH_ID as ACT_SCH_ID0_,
    activity0_.activity_num as activit11_0_,
    activity0_.state as state0_, activity0_.type as
    type0_, activity0_.ACT_PRIORITY_ID as ACT_PRI14_0_,
    activity0_.TECHN_AREA_ID as TECHN_A15_0_,
    activity0_.INFORMER_ID as INFORME16_0_,
    activity0_.target_id as target_id0_,
    activity0_.LOCAL_INFO_ID as LOCAL_I18_0_,
    activity0_.ACT_EQUIP_INFO_ID as ACT_EQU19_0_,
    activity0_.assoc_doc as assoc_doc0_,
    activity0_.free_desc as free_desc0_,
    activity0_.TECHN_AREA_RAMIF_ID as TECHN_A22_0_,
    activity0_.ACT_CLIENT_INFO_ID as ACT_CLI23_0_,
    activity0_.initial_interrupt_date as initial24_0_,
    activity0_.initial_interrupt_time as initial25_0_,
    activity0_.EXTERNAL_INFO_ID as EXTERNA26_0_,
    activity0_.CATEGORY_ID as CATEGOR27_0_,
    activity0_.CORRETIVE_INFO_ID as CORRETI28_0_,
    activity0_.RESERVER_ID as RESERVE29_0_,
    activity0_.RESERVED as RESERVED0_ from ACTIVITY
    activity0_ where activity0_.ACTIVITY_ID=?
    2005-05-13 11:35:26,191
    [net.sf.hibernate.impl.BatcherImpl] - preparing
    statement
    2005-05-13 11:35:26,199
    [net.sf.hibernate.type.LongType] - binding '18996' to
    parameter: 1
    2005-05-13 11:35:26,200
    [net.sf.hibernate.loader.Loader] - processing result
    set
    2005-05-13 11:35:26,200
    [net.sf.hibernate.loader.Loader] - result row: 18996
    2005-05-13 11:35:26,200
    [net.sf.hibernate.loader.Loader] - Initializing object
    from ResultSet: 18996
    2005-05-13 11:35:26,201
    [net.sf.hibernate.loader.Loader] - Hydrating entity:
    com.siemens.swa.domain.Activity#18996
    2005-05-13 11:35:26,204
    [net.sf.hibernate.type.LongType] - returning null as
    column: equipmen2_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.LongType] - returning null as
    column: act_velo3_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.LongType] - returning '35' as
    column: act_exec4_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.DateType] - returning null as
    column: promise_5_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.TimeType] - returning null as
    column: promise_6_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.TimestampType] - returning null
    as column: promise_7_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.TimeType] - returning null as
    column: promise_8_0_
    2005-05-13 11:35:26,205
    [net.sf.hibernate.type.BooleanType] - returning 'true'
    as column: open_che9_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.LongType] - returning null as
    column: ACT_SCH_ID0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.StringType] - returning
    'COR18996' as column: activit11_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.LongType] - returning '3' as
    column: ACT_PRI14_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.LongType] - returning '5' as
    column: TECHN_A15_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.LongType] - returning '11' as
    column: INFORME16_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.LongType] - returning '11' as
    column: LOCAL_I18_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.LongType] - returning '9' as
    column: ACT_EQU19_0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.StringType] - returning 'doc'
    as column: assoc_doc0_
    2005-05-13 11:35:26,206
    [net.sf.hibernate.type.StringType] - returning 'Bla'
    as column: free_desc0_
    2005-05-13 11:35:26,207
    [net.sf.hibernate.type.LongType] - returning '1' as
    column: TECHN_A22_0_
    2005-05-13 11:35:26,207
    [net.sf.hibernate.type.LongType] - returning null as
    column: ACT_CLI23_0_
    2005-05-13 11:35:26,207
    [net.sf.hibernate.type.TimestampType] - returning
    '2005-04-16 00:00:00' as column: initial24_0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.type.TimeType] - returning
    '11:00:00' as column: initial25_0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.type.LongType] - returning '5' as
    column: EXTERNA26_0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.type.LongType] - returning '1' as
    column: CATEGOR27_0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.type.LongType] - returning '5' as
    column: CORRETI28_0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.type.LongType] - returning '484' as
    column: RESERVE29_0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.type.BooleanType] - returning 'true'
    as column: RESERVED0_
    2005-05-13 11:35:26,213
    [net.sf.hibernate.loader.Loader] - done processing
    result set (1 rows)
    2005-05-13 11:35:26,213
    [net.sf.hibernate.impl.BatcherImpl] - done closing: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.BatcherImpl] - closing
    statement
    2005-05-13 11:35:26,214
    [net.sf.hibernate.loader.Loader] - total objects
    hydrated: 1
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - resolving
    associations for
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityExecution#35]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityPriority#3]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - creating
    collection
    wrapper:[com.siemens.swa.domain.Activity.preventiveChecklis t#18996]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.TechniqueArea#5]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.Informer#11]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityLocalInfo#11]
    2005-05-13 11:35:26,214
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityEquipmentInfo#9]
    2005-05-13 11:35:26,215
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.TechniqueAreaRamification#1]
    2005-05-13 11:35:26,215
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ExternalInfo#5]
    2005-05-13 11:35:26,215
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.ActivityCategory#1]
    2005-05-13 11:35:26,215
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.CorretiveInfo#5]
    2005-05-13 11:35:26,215
    [net.sf.hibernate.impl.SessionImpl] - loading
    [com.siemens.swa.domain.User#484]
    2005-05-13 11:35:26,216
    [net.sf.hibernate.impl.SessionImpl] - creating
    collection
    wrapper:[com.siemens.swa.domain.Activity.technicians#18996]
    2005-05-13 11:35:26,216
    [net.sf.hibernate.impl.SessionImpl] - done
    materializing entity
    [com.siemens.swa.domain.Activity#18996]
    2005-05-13 11:35:26,216
    [net.sf.hibernate.impl.SessionImpl] - initializing
    non-lazy collections
    2005-05-13 11:35:26,216
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,216
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,218
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,219
    [net.sf.hibernate.impl.SessionImpl] - find: from User
    as t where t.id = ?
    2005-05-13 11:35:26,219
    [net.sf.hibernate.engine.QueryParameters] -
    parameters: [484]
    2005-05-13 11:35:26,219
    [net.sf.hibernate.engine.QueryParameters] - named
    parameters: {}
    2005-05-13 11:35:26,219
    [net.sf.hibernate.hql.QueryTranslator] - compiling
    query
    2005-05-13 11:35:26,221
    [net.sf.hibernate.impl.SessionImpl] - flushing session
    2005-05-13 11:35:26,221
    [net.sf.hibernate.engine.Cascades] - processing
    cascades for: com.siemens.swa.domain.Activity
    2005-05-13 11:35:26,221
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    collection:
    com.siemens.swa.domain.Activity.preventiveChecklis t
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - cascading to
    collection:
    com.siemens.swa.domain.Activity.technicians
    2005-05-13 11:35:26,222
    [net.sf.hibernate.engine.Cascades] - done processing
    cascades for: com.siemens.swa.domain.Activity
    2005-05-13 11:35:26,223
    [net.sf.hibernate.impl.SessionImpl] - Flushing
    entities and processing referenced collections
    2005-05-13 11:35:26,223
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found:
    [com.siemens.swa.domain.Activity.preventiveChecklis t#18996],
    was:
    [com.siemens.swa.domain.Activity.preventiveChecklis t#18996]
    2005-05-13 11:35:26,223
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found:
    [com.siemens.swa.domain.Activity.technicians#18996],
    was:
    [com.siemens.swa.domain.Activity.technicians#18996]
    2005-05-13 11:35:26,223
    [net.sf.hibernate.impl.SessionImpl] - Processing
    unreferenced collections
    2005-05-13 11:35:26,223
    [net.sf.hibernate.impl.SessionImpl] - Scheduling
    collection removes/(re)creates/updates
    2005-05-13 11:35:26,223
    [net.sf.hibernate.impl.SessionImpl] - Flushed: 0
    insertions, 0 updates, 0 deletions to 1 objects
    2005-05-13 11:35:26,224
    [net.sf.hibernate.impl.SessionImpl] - Flushed: 0
    (re)creations, 0 updates, 0 removals to 2 collections
    2005-05-13 11:35:26,224
    [net.sf.hibernate.impl.Printer] - listing entities:
    2005-05-13 11:35:26,232
    [net.sf.hibernate.impl.Printer] -
    com.siemens.swa.domain.Activity{activityNumber=COR 18996,
    preventiveChecklist=uninitialized,
    freeDescription=Bla,
    techniqueAreaRamification=TechniqueAreaRamificatio n#1,
    equipment=null,
    activityEquipmentInfo=ActivityEquipmentInfo#9,
    initialInterruptOfServiceTime=11:00:00, id=18996,
    technicians=uninitialized, scheduleInfo=null,
    informer=Informer#11, priority=ActivityPriority#3,
    techniqueArea=TechniqueArea#5, veloxInfo=null,
    promiseDate=null,
    activityLocalInfo=ActivityLocalInfo#11,
    targetType=LOCAL, type=CORRETIVE,
    externalInfo=ExternalInfo#5, promiseEndDate=null,
    category=ActivityCategory#1,
    activityExecution=ActivityExecution#35,
    openChecklist=true, associatedDocument=doc,
    initialInterruptOfServiceDate=2005-04-16 00:00:00,
    promiseEndTime=null, reserver=User#484,
    clientInfo=null, promiseTime=null, state=EXECUTING,
    corretiveInfo=CorretiveInfo#5, reserved=true}
    2005-05-13 11:35:26,232
    [net.sf.hibernate.impl.SessionImpl] - Dont need to
    execute flush
    2005-05-13 11:35:26,232
    [net.sf.hibernate.hql.QueryTranslator] - HQL: from
    com.siemens.swa.domain.User as t where t.id = ?
    2005-05-13 11:35:26,232
    [net.sf.hibernate.hql.QueryTranslator] - SQL: select
    user0_.USER_ID as USER_ID, user0_.LOGIN as LOGIN,
    user0_.NAME as NAME, user0_.PASSWORD as PASSWORD,
    user0_.BIRTHDAY as BIRTHDAY, user0_.FATHER_NAME as
    FATHER_N6_, user0_.MOTHER_NAME as MOTHER_N7_,
    user0_.CPF as CPF, user0_.COMPLEMENT as COMPLEMENT,
    user0_.RG as RG, user0_.CATEGORY as CATEGORY,
    user0_.DRIVER_LICENSE as DRIVER_12_, user0_.PIS as
    PIS, user0_.PROF_NUMBER as PROF_NU14_, user0_.SERIES
    as SERIES, user0_.street as street, user0_.quarter as
    quarter, user0_.number as number,
    user0_.complementAddress as complem19_, user0_.cep as
    cep, user0_.city as city, user0_.state as state,
    user0_.country as country, user0_.email as email,
    user0_.phone1 as phone1, user0_.phone2 as phone2,
    user0_.phone3 as phone3, user0_.position as position,
    user0_.register1 as register1, user0_.register2 as
    register2, user0_.register3 as register3,
    user0_.register4 as register4, user0_.comment as
    comment, user0_.workLoad as workLoad, user0_.cdc as
    cdc, user0_.sector as sector, user0_.subarea as
    subarea, user0_.project as project, user0_.branch1 as
    branch1, user0_.branch2 as branch2, user0_.company as
    company, user0_.status as status, user0_.typeContract
    as typeCon43_, user0_.reason as reason,
    user0_.dateExpiration as dateExp45_,
    user0_.dateAdmission as dateAdm46_,
    user0_.dateResignation as dateRes47_ from USER user0_
    where (user0_.USER_ID=? )
    2005-05-13 11:35:26,233
    [net.sf.hibernate.impl.BatcherImpl] - about to open: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:26,234 [net.sf.hibernate.SQL] -
    select user0_.USER_ID as USER_ID, user0_.LOGIN as
    LOGIN, user0_.NAME as NAME, user0_.PASSWORD as
    PASSWORD, user0_.BIRTHDAY as BIRTHDAY,
    user0_.FATHER_NAME as FATHER_N6_, user0_.MOTHER_NAME
    as MOTHER_N7_, user0_.CPF as CPF, user0_.COMPLEMENT as
    COMPLEMENT, user0_.RG as RG, user0_.CATEGORY as
    CATEGORY, user0_.DRIVER_LICENSE as DRIVER_12_,
    user0_.PIS as PIS, user0_.PROF_NUMBER as PROF_NU14_,
    user0_.SERIES as SERIES, user0_.street as street,
    user0_.quarter as quarter, user0_.number as number,
    user0_.complementAddress as complem19_, user0_.cep as
    cep, user0_.city as city, user0_.state as state,
    user0_.country as country, user0_.email as email,
    user0_.phone1 as phone1, user0_.phone2 as phone2,
    user0_.phone3 as phone3, user0_.position as position,
    user0_.register1 as register1, user0_.register2 as
    register2, user0_.register3 as register3,
    user0_.register4 as register4, user0_.comment as
    comment, user0_.workLoad as workLoad, user0_.cdc as
    cdc, user0_.sector as sector, user0_.subarea as
    subarea, user0_.project as project, user0_.branch1 as
    branch1, user0_.branch2 as branch2, user0_.company as
    company, user0_.status as status, user0_.typeContract
    as typeCon43_, user0_.reason as reason,
    user0_.dateExpiration as dateExp45_,
    user0_.dateAdmission as dateAdm46_,
    user0_.dateResignation as dateRes47_ from USER user0_
    where (user0_.USER_ID=? )
    2005-05-13 11:35:26,234
    [net.sf.hibernate.impl.BatcherImpl] - preparing
    statement
    2005-05-13 11:35:26,234
    [net.sf.hibernate.type.LongType] - binding '484' to
    parameter: 1
    2005-05-13 11:35:26,256
    [net.sf.hibernate.loader.Loader] - processing result
    set
    2005-05-13 11:35:26,257
    [net.sf.hibernate.type.LongType] - returning '484' as
    column: USER_ID
    2005-05-13 11:35:26,257
    [net.sf.hibernate.loader.Loader] - result row: 484
    2005-05-13 11:35:26,258
    [net.sf.hibernate.loader.Loader] - Initializing object
    from ResultSet: 484
    2005-05-13 11:35:26,258
    [net.sf.hibernate.loader.Loader] - Hydrating entity:
    com.siemens.swa.domain.User#484
    2005-05-13 11:35:26,258
    [net.sf.hibernate.type.StringType] - returning
    'fulano' as column: LOGIN
    2005-05-13 11:35:26,258
    [net.sf.hibernate.type.StringType] - returning 'Fulano
    da Silva' as column: NAME
    2005-05-13 11:35:26,258
    [net.sf.hibernate.type.StringType] - returning
    'fulano' as column: PASSWORD
    2005-05-13 11:35:26,258
    [net.sf.hibernate.type.DateType] - returning '25 March
    2005' as column: BIRTHDAY
    2005-05-13 11:35:26,258
    [net.sf.hibernate.type.StringType] - returning '' as
    column: FATHER_N6_
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '' as
    column: MOTHER_N7_
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning
    '111.111.111-11' as column: CPF
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning
    'ssp/ce' as column: COMPLEMENT
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '22' as
    column: RG
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '' as
    column: CATEGORY
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '' as
    column: DRIVER_12_
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '' as
    column: PIS
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '' as
    column: PROF_NU14_
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning '' as
    column: SERIES
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning null as
    column: street
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning null as
    column: quarter
    2005-05-13 11:35:26,259
    [net.sf.hibernate.type.StringType] - returning null as
    column: number
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: complem19_
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: cep
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: city
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: state
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: country
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: email
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: phone1
    2005-05-13 11:35:26,260
    [net.sf.hibernate.type.StringType] - returning null as
    column: phone2
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: phone3
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: position
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: register1
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: register2
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: register3
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: register4
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: comment
    2005-05-13 11:35:26,261
    [net.sf.hibernate.type.StringType] - returning null as
    column: workLoad
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: cdc
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: sector
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: subarea
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: project
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: branch1
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: branch2
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: company
    2005-05-13 11:35:26,262
    [net.sf.hibernate.type.StringType] - returning null as
    column: status
    2005-05-13 11:35:26,263
    [net.sf.hibernate.type.StringType] - returning null as
    column: typeCon43_
    2005-05-13 11:35:26,263
    [net.sf.hibernate.type.StringType] - returning null as
    column: reason
    2005-05-13 11:35:26,263
    [net.sf.hibernate.type.TimestampType] - returning null
    as column: dateExp45_
    2005-05-13 11:35:26,263
    [net.sf.hibernate.type.TimestampType] - returning null
    as column: dateAdm46_
    2005-05-13 11:35:26,263
    [net.sf.hibernate.type.TimestampType] - returning null
    as column: dateRes47_
    2005-05-13 11:35:26,263
    [net.sf.hibernate.loader.Loader] - done processing
    result set (1 rows)
    2005-05-13 11:35:26,263
    [net.sf.hibernate.impl.BatcherImpl] - done closing: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:26,263
    [net.sf.hibernate.impl.BatcherImpl] - closing
    statement
    2005-05-13 11:35:26,263
    [net.sf.hibernate.loader.Loader] - total objects
    hydrated: 1
    2005-05-13 11:35:26,264
    [net.sf.hibernate.impl.SessionImpl] - resolving
    associations for [com.siemens.swa.domain.User#484]
    2005-05-13 11:35:26,264
    [net.sf.hibernate.impl.SessionImpl] - creating
    collection
    wrapper:[com.siemens.swa.domain.User.profiles#484]
    2005-05-13 11:35:26,265
    [net.sf.hibernate.impl.SessionImpl] - done
    materializing entity [com.siemens.swa.domain.User#484]
    2005-05-13 11:35:26,265
    [net.sf.hibernate.impl.SessionImpl] - initializing
    non-lazy collections
    2005-05-13 11:35:26,265
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,268
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,268
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,268
    [net.sf.hibernate.impl.SessionImpl] - find: SELECT a
    FROM Activity a WHERE a.reserver.id = ? AND a.reserved
    = ?
    2005-05-13 11:35:26,268
    [net.sf.hibernate.engine.QueryParameters] -
    parameters: [484, true]
    2005-05-13 11:35:26,268
    [net.sf.hibernate.engine.QueryParameters] - named
    parameters: {}
    2005-05-13 11:35:26,269
    [net.sf.hibernate.hql.QueryTranslator] - compiling
    query
    2005-05-13 11:35:26,276
    [net.sf.hibernate.impl.SessionImpl] - flushing session
    2005-05-13 11:35:26,276
    [net.sf.hibernate.engine.Cascades] - processing
    cascades for: com.siemens.swa.domain.Activity
    2005-05-13 11:35:26,276
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,276
    [net.sf.hibernate.engine.Cascades] - cascading to
    collection:
    com.siemens.swa.domain.Activity.preventiveChecklis t
    2005-05-13 11:35:26,276
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,276
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,277
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,277
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,277
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,277
    [net.sf.hibernate.engine.Cascades] - cascading to
    collection:
    com.siemens.swa.domain.Activity.technicians
    2005-05-13 11:35:26,277
    [net.sf.hibernate.engine.Cascades] - done processing
    cascades for: com.siemens.swa.domain.Activity
    2005-05-13 11:35:26,277
    [net.sf.hibernate.impl.SessionImpl] - Flushing
    entities and processing referenced collections
    2005-05-13 11:35:26,277
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found:
    [com.siemens.swa.domain.Activity.preventiveChecklis t#18996],
    was:
    [com.siemens.swa.domain.Activity.preventiveChecklis t#18996]
    2005-05-13 11:35:26,277
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found:
    [com.siemens.swa.domain.Activity.technicians#18996],
    was:
    [com.siemens.swa.domain.Activity.technicians#18996]
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found: [com.siemens.swa.domain.User.profiles#484],
    was: [com.siemens.swa.domain.User.profiles#484]
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.SessionImpl] - Processing
    unreferenced collections
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.SessionImpl] - Scheduling
    collection removes/(re)creates/updates
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.SessionImpl] - Flushed: 0
    insertions, 0 updates, 0 deletions to 2 objects
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.SessionImpl] - Flushed: 0
    (re)creations, 0 updates, 0 removals to 3 collections
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.Printer] - listing entities:
    2005-05-13 11:35:26,278
    [net.sf.hibernate.impl.Printer] -
    com.siemens.swa.domain.User{password=fulano, rg=22,
    contract=null, profiles=uninitialized, motherName=,
    login=fulano, address=null, complement=ssp/ce,
    category=, userCompanyInfo=null, id=484,
    cpf=111.111.111-11, contact=null, professionalNumber=,
    driverLicense=, fatherName=, pis=, name=Fulano da
    Silva, series=, birthday=25 March 2005}
    2005-05-13 11:35:26,280
    [net.sf.hibernate.impl.Printer] -
    com.siemens.swa.domain.Activity{activityNumber=COR 18996,
    preventiveChecklist=uninitialized,
    freeDescription=Bla,
    techniqueAreaRamification=TechniqueAreaRamificatio n#1,
    equipment=null,
    activityEquipmentInfo=ActivityEquipmentInfo#9,
    initialInterruptOfServiceTime=11:00:00, id=18996,
    technicians=uninitialized, scheduleInfo=null,
    informer=Informer#11, priority=ActivityPriority#3,
    techniqueArea=TechniqueArea#5, veloxInfo=null,
    promiseDate=null,
    activityLocalInfo=ActivityLocalInfo#11,
    targetType=LOCAL, type=CORRETIVE,
    externalInfo=ExternalInfo#5, promiseEndDate=null,
    category=ActivityCategory#1,
    activityExecution=ActivityExecution#35,
    openChecklist=true, associatedDocument=doc,
    initialInterruptOfServiceDate=2005-04-16 00:00:00,
    promiseEndTime=null, reserver=User#484,
    clientInfo=null, promiseTime=null, state=EXECUTING,
    corretiveInfo=CorretiveInfo#5, reserved=true}
    2005-05-13 11:35:26,280
    [net.sf.hibernate.impl.SessionImpl] - Dont need to
    execute flush
    2005-05-13 11:35:26,280
    [net.sf.hibernate.hql.QueryTranslator] - HQL: SELECT a
    FROM com.siemens.swa.domain.Activity a WHERE
    a.reserver.id = ? AND a.reserved = ?
    2005-05-13 11:35:26,280
    [net.sf.hibernate.hql.QueryTranslator] - SQL: select
    activity0_.ACTIVITY_ID as ACTIVITY1_,
    activity0_.equipment_id as equipmen2_,
    activity0_.act_velox_info_id as act_velo3_,
    activity0_.act_exec_id as act_exec4_,
    activity0_.promise_date as promise_5_,
    activity0_.promise_time as promise_6_,
    activity0_.promise_end_date as promise_7_,
    activity0_.promise_end_time as promise_8_,
    activity0_.open_checklist as open_che9_,
    activity0_.ACT_SCH_ID as ACT_SCH_ID,
    activity0_.activity_num as activit11_,
    activity0_.state as state, activity0_.type as type,
    activity0_.ACT_PRIORITY_ID as ACT_PRI14_,
    activity0_.TECHN_AREA_ID as TECHN_A15_,
    activity0_.INFORMER_ID as INFORME16_,
    activity0_.target_id as target_id,
    activity0_.LOCAL_INFO_ID as LOCAL_I18_,
    activity0_.ACT_EQUIP_INFO_ID as ACT_EQU19_,
    activity0_.assoc_doc as assoc_doc,
    activity0_.free_desc as free_desc,
    activity0_.TECHN_AREA_RAMIF_ID as TECHN_A22_,
    activity0_.ACT_CLIENT_INFO_ID as ACT_CLI23_,
    activity0_.initial_interrupt_date as initial24_,
    activity0_.initial_interrupt_time as initial25_,
    activity0_.EXTERNAL_INFO_ID as EXTERNA26_,
    activity0_.CATEGORY_ID as CATEGOR27_,
    activity0_.CORRETIVE_INFO_ID as CORRETI28_,
    activity0_.RESERVER_ID as RESERVE29_,
    activity0_.RESERVED as RESERVED from ACTIVITY
    activity0_ where (activity0_.RESERVER_ID=?
    )AND(activity0_.RESERVED=? )
    2005-05-13 11:35:26,280
    [net.sf.hibernate.impl.BatcherImpl] - about to open: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:26,280 [net.sf.hibernate.SQL] -
    select activity0_.ACTIVITY_ID as ACTIVITY1_,
    activity0_.equipment_id as equipmen2_,
    activity0_.act_velox_info_id as act_velo3_,
    activity0_.act_exec_id as act_exec4_,
    activity0_.promise_date as promise_5_,
    activity0_.promise_time as promise_6_,
    activity0_.promise_end_date as promise_7_,
    activity0_.promise_end_time as promise_8_,
    activity0_.open_checklist as open_che9_,
    activity0_.ACT_SCH_ID as ACT_SCH_ID,
    activity0_.activity_num as activit11_,
    activity0_.state as state, activity0_.type as type,
    activity0_.ACT_PRIORITY_ID as ACT_PRI14_,
    activity0_.TECHN_AREA_ID as TECHN_A15_,
    activity0_.INFORMER_ID as INFORME16_,
    activity0_.target_id as target_id,
    activity0_.LOCAL_INFO_ID as LOCAL_I18_,
    activity0_.ACT_EQUIP_INFO_ID as ACT_EQU19_,
    activity0_.assoc_doc as assoc_doc,
    activity0_.free_desc as free_desc,
    activity0_.TECHN_AREA_RAMIF_ID as TECHN_A22_,
    activity0_.ACT_CLIENT_INFO_ID as ACT_CLI23_,
    activity0_.initial_interrupt_date as initial24_,
    activity0_.initial_interrupt_time as initial25_,
    activity0_.EXTERNAL_INFO_ID as EXTERNA26_,
    activity0_.CATEGORY_ID as CATEGOR27_,
    activity0_.CORRETIVE_INFO_ID as CORRETI28_,
    activity0_.RESERVER_ID as RESERVE29_,
    activity0_.RESERVED as RESERVED from ACTIVITY
    activity0_ where (activity0_.RESERVER_ID=?
    )AND(activity0_.RESERVED=? )
    2005-05-13 11:35:26,280
    [net.sf.hibernate.impl.BatcherImpl] - preparing
    statement
    2005-05-13 11:35:26,281
    [net.sf.hibernate.type.LongType] - binding '484' to
    parameter: 1
    2005-05-13 11:35:26,281
    [net.sf.hibernate.type.BooleanType] - binding 'true'
    to parameter: 2
    2005-05-13 11:35:26,283
    [net.sf.hibernate.loader.Loader] - processing result
    set
    2005-05-13 11:35:26,283
    [net.sf.hibernate.type.LongType] - returning '18996'
    as column: ACTIVITY1_
    2005-05-13 11:35:26,284
    [net.sf.hibernate.loader.Loader] - result row: 18996
    2005-05-13 11:35:26,284
    [net.sf.hibernate.loader.Loader] - done processing
    result set (1 rows)
    2005-05-13 11:35:26,284
    [net.sf.hibernate.impl.BatcherImpl] - done closing: 0
    open PreparedStatements, 0 open ResultSets
    2005-05-13 11:35:26,284
    [net.sf.hibernate.impl.BatcherImpl] - closing
    statement
    2005-05-13 11:35:26,284
    [net.sf.hibernate.loader.Loader] - total objects
    hydrated: 0
    2005-05-13 11:35:26,284
    [net.sf.hibernate.impl.SessionImpl] - initializing
    non-lazy collections
    2005-05-13 11:35:26,284
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Retrieved value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103]
    bound to thread [http-8080-Processor23]
    2005-05-13 11:35:26,284
    [org.springframework.transaction.interceptor.Transa ctionInterceptor]
    - Invoking commit for transaction on method
    'reserveActivity' in class
    [com.siemens.swa.service.AppointmentSchedulerServic e]
    2005-05-13 11:35:26,284
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Triggering beforeCommit synchronization
    2005-05-13 11:35:26,284
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Triggering beforeCompletion synchronization
    2005-05-13 11:35:26,284
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Initiating transaction commit
    2005-05-13 11:35:26,284
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Committing Hibernate transaction on session
    [net.sf.hibernate.impl.SessionImpl@f2794a]
    2005-05-13 11:35:26,284
    [net.sf.hibernate.transaction.JDBCTransaction] -
    commit
    2005-05-13 11:35:26,285
    [net.sf.hibernate.impl.SessionImpl] - flushing session
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - processing
    cascades for: com.siemens.swa.domain.Activity
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    collection:
    com.siemens.swa.domain.Activity.preventiveChecklis t
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,285
    [net.sf.hibernate.engine.Cascades] - cascading to
    saveOrUpdate()
    2005-05-13 11:35:26,286
    [net.sf.hibernate.engine.Cascades] - cascading to
    collection:
    com.siemens.swa.domain.Activity.technicians
    2005-05-13 11:35:26,286
    [net.sf.hibernate.engine.Cascades] - done processing
    cascades for: com.siemens.swa.domain.Activity
    2005-05-13 11:35:26,286
    [net.sf.hibernate.impl.SessionImpl] - Flushing
    entities and processing referenced collections
    2005-05-13 11:35:26,286
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found:
    [com.siemens.swa.domain.Activity.preventiveChecklis t#18996],
    was:
    [com.siemens.swa.domain.Activity.preventiveChecklis t#18996]
    2005-05-13 11:35:26,286
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found:
    [com.siemens.swa.domain.Activity.technicians#18996],
    was:
    [com.siemens.swa.domain.Activity.technicians#18996]
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.SessionImpl] - Collection
    found: [com.siemens.swa.domain.User.profiles#484],
    was: [com.siemens.swa.domain.User.profiles#484]
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.SessionImpl] - Processing
    unreferenced collections
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.SessionImpl] - Scheduling
    collection removes/(re)creates/updates
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.SessionImpl] - Flushed: 0
    insertions, 0 updates, 0 deletions to 2 objects
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.SessionImpl] - Flushed: 0
    (re)creations, 0 updates, 0 removals to 3 collections
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.Printer] - listing entities:
    2005-05-13 11:35:26,287
    [net.sf.hibernate.impl.Printer] -
    com.siemens.swa.domain.User{password=fulano, rg=22,
    contract=null, profiles=uninitialized, motherName=,
    login=fulano, address=null, complement=ssp/ce,
    category=, userCompanyInfo=null, id=484,
    cpf=111.111.111-11, contact=null, professionalNumber=,
    driverLicense=, fatherName=, pis=, name=Fulano da
    Silva, series=, birthday=25 March 2005}
    2005-05-13 11:35:26,288
    [net.sf.hibernate.impl.Printer] -
    com.siemens.swa.domain.Activity{activityNumber=COR 18996,
    preventiveChecklist=uninitialized,
    freeDescription=Bla,
    techniqueAreaRamification=TechniqueAreaRamificatio n#1,
    equipment=null,
    activityEquipmentInfo=ActivityEquipmentInfo#9,
    initialInterruptOfServiceTime=11:00:00, id=18996,
    technicians=uninitialized, scheduleInfo=null,
    informer=Informer#11, priority=ActivityPriority#3,
    techniqueArea=TechniqueArea#5, veloxInfo=null,
    promiseDate=null,
    activityLocalInfo=ActivityLocalInfo#11,
    targetType=LOCAL, type=CORRETIVE,
    externalInfo=ExternalInfo#5, promiseEndDate=null,
    category=ActivityCategory#1,
    activityExecution=ActivityExecution#35,
    openChecklist=true, associatedDocument=doc,
    initialInterruptOfServiceDate=2005-04-16 00:00:00,
    promiseEndTime=null, reserver=User#484,
    clientInfo=null, promiseTime=null, state=EXECUTING,
    corretiveInfo=CorretiveInfo#5, reserved=true}
    2005-05-13 11:35:26,288
    [net.sf.hibernate.impl.SessionImpl] - executing flush
    2005-05-13 11:35:26,288
    [net.sf.hibernate.impl.SessionImpl] - post flush
    2005-05-13 11:35:26,289
    [net.sf.hibernate.impl.SessionImpl] - transaction
    completion
    2005-05-13 11:35:26,289
    [net.sf.hibernate.transaction.JDBCTransaction] -
    re-enabling autocommit
    2005-05-13 11:35:26,289
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Triggering afterCompletion synchronization
    2005-05-13 11:35:26,289
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Clearing transaction synchronization
    2005-05-13 11:35:26,289
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Removed value
    [org.springframework.orm.hibernate.SessionHolder@6c a716]
    for key
    [net.sf.hibernate.impl.SessionFactoryImpl@d26103] from
    thread [http-8080-Processor23]
    2005-05-13 11:35:26,290
    [org.springframework.transaction.support.Transactio nSynchronizationManager]
    - Removed value
    [org.springframework.jdbc.datasource.ConnectionHold er@14a3347]
    for key
    [com.mysql.jdbc.jdbc2.optional.MysqlDataSource@d86c 58]
    from thread [http-8080-Processor23]
    2005-05-13 11:35:26,290
    [org.springframework.orm.hibernate.HibernateTransac tionManager]
    - Closing Hibernate session
    [net.sf.hibernate.impl.SessionImpl@f2794a] after
    transaction
    2005-05-13 11:35:26,290
    [org.springframework.orm.hibernate.SessionFactoryUt ils]
    - Closing Hibernate session
    2005-05-13 11:35:26,290
    [net.sf.hibernate.impl.SessionImpl] - closing session
    2005-05-13 11:35:26,290
    [net.sf.hibernate.impl.SessionImpl] - disconnecting
    session
    2005-05-13 11:35:26,290
    [net.sf.hibernate.impl.SessionImpl] - transaction
    completion
    2005-05-13 11:35:26,296
    [net.sf.hibernate.proxy.LazyInitializer] - Exception
    initializing proxy
    net.sf.hibernate.HibernateException: Could not
    initialize proxy - the owning Session was closed
    at
    net.sf.hibernate.proxy.LazyInitializer.initialize( LazyInitializer.java:47)
    at
    net.sf.hibernate.proxy.LazyInitializer.initializeW rapExceptions(LazyInitializer.java:60)
    at
    net.sf.hibernate.proxy.LazyInitializer.getImplemen tation(LazyInitializer.java:164)
    at
    net.sf.hibernate.proxy.CGLIBLazyInitializer.interc ept(CGLIBLazyInitializer.java:108)
    at
    com.siemens.swa.domain.ActivityPriority$$EnhancerB yCGLIB$$e4c4a28d.toString(<generated>)
    at java.lang.String.valueOf(String.java:2131)
    at
    java.lang.StringBuffer.append(StringBuffer.java:37 0)
    at
    com.siemens.swa.domain.Activity.toString(Activity. java:887)
    at java.lang.String.valueOf(String.java:2131)
    at
    java.lang.StringBuffer.append(StringBuffer.java:37 0)
    at
    com.siemens.swa.util.log.SpringLogDebugReturnAspec t.afterReturning(SpringLogDebugReturnAspect.java:5 4)
    at
    org.springframework.aop.framework.adapter.AfterRet urningAdviceInterceptor.invoke(AfterReturningAdvic eInterceptor.java:52)
    at
    org.springframework.aop.framework.ReflectiveMethod Invocation.proceed(ReflectiveMethodInvocation.java :144)
    at
    org.springframework.aop.framework.JdkDynamicAopPro xy.invoke(JdkDynamicAopProxy.java:174)
    at $Proxy1.reserveActivity(Unknown S

  • #2
    <filter>
    <filter-name>hibernate</filter-name>
    <filter-class>com.siemens.swa.util.persistence.HibernateSe ssionFilter</filter-class>
    <init-param>
    <param-name>singleSession</param-name>
    <param-value>true</param-value>
    </init-param>
    <init-param>
    <param-name>sessionFactoryBeanName</param-name>
    <param-value>mySessionFactory</param-value>
    </init-param>
    </filter>

    <filter-mapping>
    <filter-name>hibernate</filter-name>
    <url-pattern>*.do</url-pattern>
    </filter-mapping>

    <filter-mapping>
    <filter-name>hibernate</filter-name>
    <url-pattern>*.jsp</url-pattern>
    </filter-mapping>
    I am not familiar with Struts structure on the web but try using a general url-pattern - *.
    I saw you are extending the OpenSessionInView - have you tried with the default filter ?

    As I see the problem occurs inside your logging aspect (where you call a toString):
    com.siemens.swa.util.log.SpringLogDebugReturnAspec t.afterReturning(SpringLogDebugReturnAspect.java:5 4)
    Try to put some logging inside the filter to see where the session is opened and closed - probably is closed somewhere along the road.

    Comment


    • #3
      Hi costin, thanks for the ideas. I tried changing the filter to '*' and using the default OpenSessionInViewFilter, but unfortunately I get the same result.

      The logs are indeed long and easy to miss stuff - you can see all the entire logs and my *.xml files here:

      http://www.braziloutsource.com/random/logs/

      In the logs I've divided the server startup, and the problem request at:

      HTTP REQUEST WITH EXCEPTION STARTS HERE

      Anyways, in the Apache log right after that you will see:

      2005-05-13 11:35:19,758 [org.apache.catalina.core.StandardWrapper] - Returning non-STM instance
      2005-05-13 11:35:19,758 [org.springframework.beans.factory.support.DefaultL istableBeanFactory] - Returning cached instance of singleton bean 'mySessionFactory'
      2005-05-13 11:35:19,758 [org.springframework.beans.factory.support.DefaultL istableBeanFactory] - Bean with name 'mySessionFactory' is a factory bean
      2005-05-13 11:35:19,759 [org.springframework.orm.hibernate.SessionFactoryUt ils] - Opening Hibernate session
      ...

      2005-05-13 11:35:19,776 [org.springframework.web.struts.DelegatingActionUti ls] - DelegatingActionProxy with mapping path '/TrackingExecutionOperation' and module prefix '' delegating to Spring bean with name [/TrackingExecutionOperation]
      2005-05-13 11:35:19,776 [org.springframework.beans.factory.support.DefaultL istableBeanFactory] - Returning cached instance of singleton bean '/TrackingExecutionOperation'

      However, I milli second later in my app log you will also see:

      2005-05-13 11:35:19,759 [com.siemens.swa.util.persistence.HibernateSessionF ilter] - Opening single Hibernate session in OpenSessionInViewFilter

      Going back to the Apache log, the Session gets closed on the completion of the transaction:

      ...

      2005-05-13 11:35:26,288 [net.sf.hibernate.impl.SessionImpl] - executing flush
      2005-05-13 11:35:26,288 [net.sf.hibernate.impl.SessionImpl] - post flush
      2005-05-13 11:35:26,289 [net.sf.hibernate.impl.SessionImpl] - transaction completion
      2005-05-13 11:35:26,289 [net.sf.hibernate.transaction.JDBCTransaction] - re-enabling autocommit
      2005-05-13 11:35:26,289 [org.springframework.orm.hibernate.HibernateTransac tionManager] - Triggering afterCompletion synchronization
      2005-05-13 11:35:26,289 [org.springframework.transaction.support.Transactio nSynchronizationManager] - Clearing transaction synchronization
      2005-05-13 11:35:26,289 [org.springframework.transaction.support.Transactio nSynchronizationManager] - Removed value [org.springframework.orm.hibernate.SessionHolder@6c a716] for key [net.sf.hibernate.impl.SessionFactoryImpl@d26103] from thread [http-8080-Processor23]
      2005-05-13 11:35:26,290 [org.springframework.transaction.support.Transactio nSynchronizationManager] - Removed value [org.springframework.jdbc.datasource.ConnectionHold er@14a3347] for key [com.mysql.jdbc.jdbc2.optional.MysqlDataSource@d86c 58] from thread [http-8080-Processor23]
      2005-05-13 11:35:26,290 [org.springframework.orm.hibernate.HibernateTransac tionManager] - Closing Hibernate session [net.sf.hibernate.impl.SessionImpl@f2794a] after transaction
      2005-05-13 11:35:26,290 [org.springframework.orm.hibernate.SessionFactoryUt ils] - Closing Hibernate session
      2005-05-13 11:35:26,290 [net.sf.hibernate.impl.SessionImpl] - closing session
      2005-05-13 11:35:26,290 [net.sf.hibernate.impl.SessionImpl] - disconnecting session
      2005-05-13 11:35:26,290 [net.sf.hibernate.impl.SessionImpl] - transaction completion
      2005-05-13 11:35:26,296 [net.sf.hibernate.proxy.LazyInitializer] - Exception initializing proxy
      net.sf.hibernate.HibernateException: Could not initialize proxy - the owning Session was closed

      Yet, my Filter closes seemingly another, completely unrelated Session after the exception:

      2005-05-13 11:35:26,368 [com.siemens.swa.util.persistence.HibernateSessionF ilter] - Closing single Hibernate session in OpenSessionInViewFilter

      Inspecting the two Sessions objects with a debugger shows a var that holds a timestamp - and those values are different. I'm not sure if that is absolute proof of two seperate sessions, but that andthe logs seem to indicate to me there are two sessions.

      My question remains. How is it possible for HibernateDAOSupport to ignore my ThreadLocal session and create another session? Is this due to the Struts Action, listed here as:

      [org.springframework.beans.factory.support.DefaultL istableBeanFactory] - Returning cached instance of singleton bean '/TrackingExecutionOperation'

      Causing the problem, ie, starting another session?
      Please help,
      iksrazal

      Comment


      • #4
        What about this thread.
        I think your OSIV filter is correct and the problem lies in loading the Spring context. I haven't used Struts inside my apps but I recommend to take a look at some examples out there (like appfuse).

        Comment

        Working...
        X