session.save(object) doesn't save nor throws exception

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

Need help with Hibernate? Read this first:
http://www.hibernate.org/ForumMailingli ... AskForHelp

Hibernate version: 3

Mapping documents:

Code between sessionFactory.openSession() and session.close():
try
{
Component component = new Component();
component.setAttr((String) request.getParameter("Attr"));

// Saves the new object
s.save(component);
}
catch (Exception e)
{
request.setAttribute("EXCEPTION", e.getMessage());
strReturn = "fail";
}

Full stack trace of any exception that occurs:

Name and version of the database you are using: Oracle 9i

The generated SQL (show_sql=true):

Debug level Hibernate log excerpt:

So, i have that code above but it neithers saves the object into the database nor throws and exception. My struts keeps goind as if everything went OK, only the object is not saved to the database.

Weeeiiiiirrrrrd.

Thanks a lot to all.
Eduardo

kochcp · **Posted:** Thu Nov 03, 2005 3:00 pm

I don't mean to sound rude, but it is impossible to tell what you could be doing wrong when you post one line of hibernate code.

http://www.hibernate.org/ForumMailingli ... AskForHelp

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

kochcp wrote:

I don't mean to sound rude, but it is impossible to tell what you could be doing wrong when you post one line of hibernate code.

http://www.hibernate.org/ForumMailingli ... AskForHelp

Don't worry, you're not being rude, you're just not understanding what's happening.

I didn't "post one line of hibernate code". I posted all the lines of hibernate code. That's all i have in my action. It's instantiating and object, setting one attribute, and saving it. There's nothing more. That's it.

And believe me, if i weren't seeing it execute the save command and NOT save it, i likely i wouldn't believe it either.

Thanks for the reply.
Eduardo

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

More precisely, here's the entire content of the java file:

Code:

// XSL source (default): platform:/plugin/com.genuitec.eclipse.cross.easystruts.eclipse_4.0.1/xslt/JavaClass.xsl

package mypackage.struts;

import mypackage.Component;
import mypackage.Hibernate.HibernateSessionFactory;
import org.apache.struts.action.Action;
import org.apache.struts.action.ActionForm;
import org.apache.struts.action.ActionMapping;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import org.apache.struts.action.ActionForward;
import org.apache.struts.action.ActionError;
import org.apache.struts.action.ActionErrors;
import java.io.IOException;
import javax.servlet.ServletException;
import org.hibernate.Session;

/** 
 * MyEclipse Struts
 * Creation date: 10-25-2005
 * 
 * XDoclet definition:
 * @struts.action path="/component-insert" name="componentForm" scope="request" validate="true"
 */
public class Component_InsertAction extends Action {

   // --------------------------------------------------------- Instance Variables

   // --------------------------------------------------------- Methods

   /** 
    * Method execute
    * @param mapping
    * @param form
    * @param request
    * @param response
    * @return ActionForward
    */
   public ActionForward execute(
      ActionMapping mapping,
      ActionForm form,
      HttpServletRequest request,
      HttpServletResponse response) {

        String strReturn = "success";

        // Retrieves a session to the database 
        Session s = HibernateSessionFactory.currentSession();
        try
        {
            Component component = new Component();
            component.setAttr((String) request.getParameter("Attr"));

            // Saves the new object
            s.save(component);
        }
        catch (Exception e)
        {
            request.setAttribute("EXCEPTION", e.getMessage());
            strReturn = "fail";
        }

        // Closes the database session
        HibernateSessionFactory.closeSession();
        
        return mapping.findForward(strReturn);
   }

}

And the HibernateSessionFactory class is the default generated by MyEclipse:

Code:

package mypackage.Hibernate
import org.hibernate.HibernateException;
import org.hibernate.Session;
import org.hibernate.cfg.Configuration;

/**
 * Configures and provides access to Hibernate sessions, tied to the
 * current thread of execution.  Follows the Thread Local Session
 * pattern, see {@link http://hibernate.org/42.html}.
 */
public class HibernateSessionFactory {

    /** 
     * Location of hibernate.cfg.xml file.
     * NOTICE: Location should be on the classpath as Hibernate uses
     * #resourceAsStream style lookup for its configuration file. That
     * is place the config file in a Java package - the default location
     * is the default Java package.<br><br>
     * Examples: <br>
     * <code>CONFIG_FILE_LOCATION = "/hibernate.conf.xml". 
     * CONFIG_FILE_LOCATION = "/com/foo/bar/myhiberstuff.conf.xml".</code> 
     */
    private static String CONFIG_FILE_LOCATION = "/hibernate.cfg.xml";

    /** Holds a single instance of Session */
    private static final ThreadLocal threadLocal = new ThreadLocal();

    /** The single instance of hibernate configuration */
    private static final Configuration cfg = new Configuration();

    /** The single instance of hibernate SessionFactory */
    private static org.hibernate.SessionFactory sessionFactory;

    /**
     * Returns the ThreadLocal Session instance.  Lazy initialize
     * the <code>SessionFactory</code> if needed.
     *
     *  @return Session
     *  @throws HibernateException
     */
    public static Session currentSession() throws HibernateException {
        Session session = (Session) threadLocal.get();

        if (session == null) {
            if (sessionFactory == null) {
                try {
                    cfg.configure(CONFIG_FILE_LOCATION);
                    sessionFactory = cfg.buildSessionFactory();
                }
                catch (Exception e) {
                    System.err.println("%%%% Error Creating SessionFactory %%%%");
                    e.printStackTrace();
                }
            }
            session = sessionFactory.openSession();
            threadLocal.set(session);
        }

        return session;
    }

    /**
     *  Close the single hibernate session instance.
     *
     *  @throws HibernateException
     */
    public static void closeSession() throws HibernateException {
        Session session = (Session) threadLocal.get();
        threadLocal.set(null);

        if (session != null) {
            session.close();
        }
    }

    /**
     * Default constructor.
     */
    private HibernateSessionFactory() {
    }

}

dlmiles · **Posted:** Thu Nov 03, 2005 3:32 pm

emylonas wrote:

// Saves the new object
s.save(component);

Does it work if you:

s.save(component);
s.flush();

For non-identiy tables the save maybe delayed, for IDENTITY tables the save would usualy happen right away.

If the flush() is the problem, have you looked at one of the Servlet design patterns to use with hibernate to ensure correct operation.

My 2 cents.

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

dlmiles wrote:

emylonas wrote:

// Saves the new object
s.save(component);

Does it work if you:

s.save(component);
s.flush();

For non-identiy tables the save maybe delayed, for IDENTITY tables the save would usualy happen right away.

If the flush() is the problem, have you looked at one of the Servlet design patterns to use with hibernate to ensure correct operation.

My 2 cents.

I appreciate that, but it didn't work. Unfortunately, the behavior is still the same. No exceptions and no object in the database.

I've already seen that design pattern, but i'm first trying to get this part goind prior to trying something more advanced.

Thanks a lot for the reply.
Eduardo

dlmiles · **Posted:** Thu Nov 03, 2005 4:15 pm

Next plan of attack... confirm an see for yourself what Hibernate is doing.

Try adding hibernate.properties:

Code:

hibernate.show_sql=true

Try setting in log4j.properties (I presume you are using log4j) try uncommenting some of these and changing to INFO to DEBUG for more verbose output:

Code:

log4j.rootLogger=INFO, stdout, tmpfile
log4j.rootCategory=INFO

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Threshold=DEBUG
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%-5p %d{HH:mm:ss,SSS} (%F:%M:%L)  -%m%n

log4j.appender.tmpfile=org.apache.log4j.RollingFileAppender
log4j.appender.tmpfile.File=/tmp/java.log
log4j.appender.tmpfile.Threshold=DEBUG
log4j.appender.tmpfile.MaxBackupIndex=10
log4j.appender.tmpfile.MaxFileSize=8192Kb
log4j.appender.tmpfile.layout=org.apache.log4j.PatternLayout
log4j.appender.tmpfile.layout.ConversionPattern=%-5p[%t] %d{HH:mm:ss,SSS} (%F:%M:%L)  -%m%n

log4j.logger.org.hibernate=DEBUG
# Log all SQL DML statements as they are executed
##log4j.logger.org.hibernate.sql=INFO
# Log all JDBC parameters
log4j.logger.org.hibernate.type=INFO
# Log all SQL DDL statements as they are executed
#log4j.logger.org.hibernate.tool.hbm2ddl
# Log the state of all entities (max 20 entities) associated with the session at flush time
#log4j.logger.org.hibernate.pretty=DEBUG
# Log all second-level cache activity
#log4j.logger.org.hibernate.cache
# Log transaction related activity
log4j.logger.org.hibernate.transaction=DEBUG
# Log all JDBC resource acquisition
#log4j.logger.org.hibernate.jdbc
# Log HQL and SQL ASTs and other information about query parsing
#log4j.logger.org.hibernate.hql.ast
# Log all JAAS authorization requests
#log4j.logger.org.hibernate.secure
# Log everything (a lot of information, but very useful for troubleshooting)
#log4j.logger.org.hibernate

##log4j.logger.org.hibernate.jdbc.ConnectionManager=TRACE
##log4j.logger.org.hibernate.jdbc.JDBCContext=TRACE

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

OK... so tha'ts exaclty what i did. The output is copied below.

I can see what's going on, but i couldn't figure out what's wrong. There's this line saying "success of batch update unknown: 0". I can only understand that's bad.

I'll keep digging.

Thanks a lot for all the help.
Eduardo

Code:

DEBUG 09:00:53,226 (SessionImpl.java:<init>:250)  -opened session at timestamp: 4632994010013696
 DEBUG 09:00:53,246 (DefaultSaveOrUpdateEventListener.java:entityIsTransient:159)  -saving transient instance
 DEBUG 09:00:53,256 (AbstractBatcher.java:logOpenPreparedStatement:290)  -about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
 DEBUG 09:00:53,256 (ConnectionManager.java:openConnection:296)  -opening JDBC connection
 DEBUG 09:00:53,256 (DriverManagerConnectionProvider.java:getConnection:93)  -total checked-out connections: 0
 DEBUG 09:00:53,256 (DriverManagerConnectionProvider.java:getConnection:99)  -using pooled JDBC connection, pool size: 0
 DEBUG 09:00:53,266 (AbstractBatcher.java:log:324)  -select SEQTCOMPONENT.nextval from dual
 Hibernate: select SEQTCOMPONENT.nextval from dual
DEBUG 09:00:53,266 (AbstractBatcher.java:getPreparedStatement:378)  -preparing statement
 DEBUG 09:00:53,287 (SequenceGenerator.java:generate:87)  -Sequence identifier generated: 11
 DEBUG 09:00:53,287 (AbstractBatcher.java:logClosePreparedStatement:298)  -about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
 DEBUG 09:00:53,287 (AbstractBatcher.java:closePreparedStatement:416)  -closing statement
 DEBUG 09:00:53,297 (AbstractSaveEventListener.java:saveWithGeneratedId:100)  -generated identifier: 11, using strategy: org.hibernate.id.SequenceGenerator
 DEBUG 09:00:53,297 (AbstractSaveEventListener.java:performSave:133)  -saving [mypackage.Component#11]
 DEBUG 09:00:53,507 (AbstractFlushingEventListener.java:flushEverythingToExecutions:52)  -flushing session
 DEBUG 09:00:53,507 (AbstractFlushingEventListener.java:prepareEntityFlushes:102)  -processing flush-time cascades
 DEBUG 09:00:53,507 (AbstractFlushingEventListener.java:prepareCollectionFlushes:150)  -dirty checking collections
 DEBUG 09:00:53,517 (AbstractFlushingEventListener.java:flushEntities:167)  -Flushing entities and processing referenced collections
 DEBUG 09:00:53,517 (AbstractFlushingEventListener.java:flushCollections:203)  -Processing unreferenced collections
 DEBUG 09:00:53,517 (AbstractFlushingEventListener.java:flushCollections:217)  -Scheduling collection removes/(re)creates/updates
 DEBUG 09:00:53,517 (AbstractFlushingEventListener.java:flushEverythingToExecutions:79)  -Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
 DEBUG 09:00:53,517 (AbstractFlushingEventListener.java:flushEverythingToExecutions:85)  -Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
 DEBUG 09:00:53,517 (Printer.java:toString:83)  -listing entities:
 DEBUG 09:00:53,517 (Printer.java:toString:90)  -mypackage.Component{componentDesc=1 comp, componentNum=11}
 DEBUG 09:00:53,517 (AbstractFlushingEventListener.java:performExecutions:267)  -executing flush
 DEBUG 09:00:53,527 (BasicEntityPersister.java:insert:1825)  -Inserting entity: [mypackage.Component#11]
 DEBUG 09:00:53,527 (AbstractBatcher.java:logOpenPreparedStatement:290)  -about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
 DEBUG 09:00:53,527 (AbstractBatcher.java:log:324)  -insert into TBLTCOMPONENT (COMPONENT_DESC, COMPONENT_NUM) values (?, ?)
 Hibernate: insert into TBLTCOMPONENT (COMPONENT_DESC, COMPONENT_NUM) values (?, ?)
DEBUG 09:00:53,527 (AbstractBatcher.java:getPreparedStatement:378)  -preparing statement
 DEBUG 09:00:53,527 (BasicEntityPersister.java:dehydrate:1612)  -Dehydrating entity: [mypackage.Component#11]
 DEBUG 09:00:53,537 (NullableType.java:nullSafeSet:59)  -binding '1 comp' to parameter: 1
 DEBUG 09:00:53,567 (NullableType.java:nullSafeSet:59)  -binding '11' to parameter: 2
 DEBUG 09:00:53,567 (BatchingBatcher.java:addToBatch:27)  -Adding to batch
 DEBUG 09:00:53,567 (BatchingBatcher.java:doExecuteBatch:54)  -Executing batch size: 1
 DEBUG 09:00:53,627 (BatchingBatcher.java:checkRowCount:84)  -success of batch update unknown: 0
 DEBUG 09:00:53,627 (AbstractBatcher.java:logClosePreparedStatement:298)  -about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
 DEBUG 09:00:53,627 (AbstractBatcher.java:closePreparedStatement:416)  -closing statement
 DEBUG 09:00:53,637 (AbstractFlushingEventListener.java:postFlush:294)  -post flush
 DEBUG 09:00:53,637 (SessionImpl.java:close:269)  -closing session
 DEBUG 09:00:53,637 (ConnectionManager.java:closeConnection:317)  -closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
 DEBUG 09:00:53,637 (DriverManagerConnectionProvider.java:closeConnection:129)  -returning connection to pool, pool size: 1
 DEBUG 09:00:53,637 (JDBCContext.java:afterTransactionCompletion:283)  -after transaction completion
 DEBUG 09:00:53,637 (SessionImpl.java:afterTransactionCompletion:403)  -after transaction completion
 DEBUG 09:00:53,647 (SessionImpl.java:<init>:250)  -opened session at timestamp: 4632994011738112
 intIndex: 1
DEBUG 09:00:53,647 (AbstractBatcher.java:logOpenPreparedStatement:290)  -about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
 DEBUG 09:00:53,657 (ConnectionManager.java:openConnection:296)  -opening JDBC connection
 DEBUG 09:00:53,657 (DriverManagerConnectionProvider.java:getConnection:93)  -total checked-out connections: 0
 DEBUG 09:00:53,657 (DriverManagerConnectionProvider.java:getConnection:99)  -using pooled JDBC connection, pool size: 0
 DEBUG 09:00:53,657 (AbstractBatcher.java:log:324)  -select this_.COMPONENT_NUM as COMPONENT1_0_, this_.COMPONENT_DESC as COMPONENT3_57_0_ where this_.COMPONENT_DESC like ? order by this_.COMPONENT_DESC asc
 Hibernate: select this_.COMPONENT_NUM as COMPONENT1_0_, this_.COMPONENT_DESC as COMPONENT3_57_0_ where this_.COMPONENT_DESC like ? order by this_.COMPONENT_DESC asc
DEBUG 09:00:53,657 (AbstractBatcher.java:getPreparedStatement:378)  -preparing statement
 DEBUG 09:00:53,657 (NullableType.java:nullSafeSet:59)  -binding '1 comp%' to parameter: 1
 DEBUG 09:00:53,667 (AbstractBatcher.java:logOpenResults:306)  -about to open ResultSet (open ResultSets: 0, globally: 0)
 DEBUG 09:00:53,667 (Loader.java:doQuery:405)  -processing result set
 DEBUG 09:00:53,747 (Loader.java:doQuery:429)  -done processing result set (0 rows)
 DEBUG 09:00:53,747 (AbstractBatcher.java:logCloseResults:313)  -about to close ResultSet (open ResultSets: 1, globally: 1)
 DEBUG 09:00:53,757 (AbstractBatcher.java:logClosePreparedStatement:298)  -about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
 DEBUG 09:00:53,827 (AbstractBatcher.java:closePreparedStatement:416)  -closing statement
 DEBUG 09:00:53,837 (Loader.java:initializeEntitiesAndCollections:528)  -total objects hydrated: 0
 DEBUG 09:00:53,837 (PersistenceContext.java:initializeNonLazyCollections:789)  -initializing non-lazy collections
 DEBUG 09:00:53,837 (JDBCContext.java:afterNontransactionalQuery:322)  -after autocommit
 

CollinL · **Joined:** Wed Feb 02, 2005 6:33 am **Posts:** 70

Try:

Code:

        Session s = HibernateSessionFactory.currentSession();
        Transaction t = s.beginTransaction(); // *****
        try
        {
            Component component = new Component();
            component.setAttr((String) request.getParameter("Attr"));

            // Saves the new object
            s.save(component);
            t.commit();
        }
        catch (Exception e)
        {
            request.setAttribute("EXCEPTION", e.getMessage());
            strReturn = "fail";
            t.rollback();
        }

        // Closes the database session
        HibernateSessionFactory.closeSession(); 

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

Wow, that seemed to be would be it, but unfortunately didn't work.

One thing i remembered is that i have a one-to-many relationship, mapped as a Set variable (which i didn't post here for securitiy issues...). I tried to initialize this variable in the constructor method, but that didn't make a difference either.

Thanks a lot for the reply

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

I even thought the problem could be the jdbc driver. I downloaded a new one from otn, but nothing changed. Then i noticed MyEclipse provides it own driver, but it didn't work either.

I migrated my application to JDeveloper, maybe the problem could be with MyEclipse, but i keep having the same problem. So i figure there's gotta be something with my mappings or hibernate-config.

Does anybody have an idea?

Thanks a lot

dlmiles · **Posted:** Mon Nov 07, 2005 10:45 am

emylonas wrote:

Does anybody have an idea?

Have you uncommented more JDBC related logging ?

Can you paste your SessionFactory construction output ?

jamie_dainton · **Posted:** Mon Nov 07, 2005 11:03 am

Try starting a transaction and then commiting the transaction.

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

dlmiles wrote:

emylonas wrote:

Does anybody have an idea?

Have you uncommented more JDBC related logging ?

Can you paste your SessionFactory construction output ?

I'm sorry. I don't understand exaclty what you mean by "SessionFactory construction output ". If that's the log generated when the SessionFactory is created, i think i'm posting it below.

I'll try to look for more output.

Thanks a lot for the help.

Code:

 DEBUG 12:18:52,602 (SessionFactoryObjectFactory.java:<clinit>:39)  -initializing class SessionFactoryObjectFactory
 DEBUG 12:18:52,622 (SessionFactoryObjectFactory.java:addInstance:76)  -registered: 8a81bb73076b17c301076b17fb260000 (unnamed)
 INFO  12:18:52,622 (SessionFactoryObjectFactory.java:addInstance:82)  -Not binding factory to JNDI, no JNDI name configured
 DEBUG 12:18:52,622 (SessionFactoryImpl.java:<init>:262)  -instantiated session factory
 INFO  12:18:52,632 (SessionFactoryImpl.java:checkNamedQueries:379)  -Checking 0 named queries
 DEBUG 12:18:52,753 (SessionImpl.java:<init>:250)  -opened session at timestamp: 4634104351301632
 DEBUG 12:18:52,833 (AbstractBatcher.java:logOpenPreparedStatement:290)  -about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
 DEBUG 12:18:52,843 (ConnectionManager.java:openConnection:296)  -opening JDBC connection
 DEBUG 12:18:52,843 (DriverManagerConnectionProvider.java:getConnection:93)  -total checked-out connections: 0
 DEBUG 12:18:52,843 (DriverManagerConnectionProvider.java:getConnection:99)  -using pooled JDBC connection, pool size: 0

emylonas · **Joined:** Thu Aug 04, 2005 2:24 pm **Posts:** 45

jamie_dainton wrote:

Try starting a transaction and then commiting the transaction.

Already done that. Didn't work. I thought that was a winner, but unfortunately no.

Thanks a lot for the help