Hibernate Optimistic Locking : Not getting any exception

Question

I am trying to update the same row in different transaction to understand the optimistic locking of Hibernate.

But I am not getting any StaleObjectStateException or any other exception.

public void updateUsingTwoThreads() throws InterruptedException {
        Thread t1 = new Thread(new Runnable() {
            public void run() {
                Session session = null;
                try {
                    session = HibernateUtil.getSessionFactory().openSession();
                    org.hibernate.Transaction transaction = session
                            .beginTransaction();
                    Airline airline = (Airline) session.get(Airline.class,
                            new Integer(1));
                    System.out.println("getVersion in "+airline.getVersion()+"in "+ Thread.currentThread().getName());
                    try {
                        Thread.sleep(2000);
                    } catch (InterruptedException e) {
                        // TODO Auto-generated catch block
                        e.printStackTrace();
                    }

                    airline.setAirlineCode("asdasd234phle");
                    session.saveOrUpdate(airline);
                    System.out.println("getVersion in "+airline.getVersion()+"in "+ Thread.currentThread().getName());
                    transaction.commit();
                }catch(Throwable t){
                    System.out.println(t);

                }finally {
                    session.close();
                }
            }
        },"earlier");

        Thread t2 = new Thread(new Runnable() {
            public void run() {
                Session session = null;
                try {
                    session = HibernateUtil.getSessionFactory().openSession();
                    //session.clear();
                    org.hibernate.Transaction transaction = session.beginTransaction();
                    Airline airline = (Airline) session.get(Airline.class,new Integer(1));
                    System.out.println("getVersion in "+airline.getVersion()+"in "+ Thread.currentThread().getName());
                    try {
                        Thread.sleep(100000);
                    } catch (InterruptedException e) {
                        // TODO Auto-generated catch block
                        e.printStackTrace();
                    }
                    System.out.println("getVersion in "+airline.getVersion()+"in "+ Thread.currentThread().getName());
                    airline.setAirlineCode("asdasdbaadmain");
                    session.saveOrUpdate(airline);
                    transaction.commit();
                }catch(Throwable t){
                    System.out.println(t);

                } finally {
                    session.close();
                }
            }
        },"later");

        t1.start();
        t2.start();

        t1.join();
        t2.join();

    }

I have attached the code above what I am trying to do. Please let me know ..Do I missing something?

Or Optimistic locking is something different than what I am trying to do.

In the above code, I have started two thread "Earlier" and "Later", both are getting the session object from sessionFactory and loading the same record from Database and updating it concurrently.

1) But no exception is coming, and Also only one thread is able to update the row.

Airline class is attached below:

package tryouts.one_to_many;

import java.io.Serializable;
import java.util.HashSet;
import java.util.Set;

import javax.persistence.Column;
import javax.persistence.Entity;
import javax.persistence.GeneratedValue;
import javax.persistence.GenerationType;
import javax.persistence.Id;
import javax.persistence.JoinColumn;
import javax.persistence.OneToMany;
import javax.persistence.Version;

import org.hibernate.annotations.OptimisticLockType;

@Entity
@org.hibernate.annotations.Entity(dynamicUpdate=true, optimisticLock = OptimisticLockType.ALL)
public class Airline implements Serializable {

    private static final long serialVersionUID = 1L;

    @Id
    @GeneratedValue(strategy = GenerationType.AUTO)
    @Column(name = "AIRLINE_ID")
    private Integer airlineId;

    @Column(name = "AIRLINE_NAME")
    private String airlineName;

    @Column(name = "AIRLINE_CODE")
    private String airlineCode;

    @Version 
    private long version;

    @OneToMany
    @JoinColumn(name="airlineId")
    private Set<AirlineFlight> airlineFlights = new HashSet<AirlineFlight>();

    public Integer getAirlineId() {
        return airlineId;
    }

    public void setAirlineId(Integer airlineId) {
        this.airlineId = airlineId;
    }

    public String getAirlineName() {
        return airlineName;
    }

    public void setAirlineName(String airlineName) {
        this.airlineName = airlineName;
    }

    public String getAirlineCode() {
        return airlineCode;
    }

    public void setAirlineCode(String airlineCode) {
        this.airlineCode = airlineCode;
    }

    public Set<AirlineFlight> getAirlineFlights() {
        return airlineFlights;
    }

    public void setAirlineFlights(Set<AirlineFlight> airlineFlights) {
        this.airlineFlights = airlineFlights;
    }

    public long getVersion() {
        return version;
    }

    public void setVersion(long version) {
        this.version = version;
    }

}

Program OutPut:

 04:25:29.656 [earlier] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13645311296
04:25:29.656 [later] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 13645311296
04:25:29.657 [earlier] DEBUG o.h.transaction.JDBCTransaction - begin
04:25:29.657 [later] DEBUG o.h.transaction.JDBCTransaction - begin
04:25:29.657 [earlier] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
04:25:29.657 [later] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
04:25:29.657 [earlier] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
04:25:29.657 [later] DEBUG o.h.c.DriverManagerConnectionProvider - opening new JDBC connection
04:25:29.659 [earlier] DEBUG org.hibernate.loader.Loader - loading entity: [tryouts.one_to_many.Airline#1]
04:25:29.663 [earlier] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
04:25:29.663 [earlier] DEBUG org.hibernate.SQL - select airline0_.AIRLINE_ID as AIRLINE1_0_0_, airline0_.AIRLINE_CODE as AIRLINE2_0_0_, airline0_.AIRLINE_NAME as AIRLINE3_0_0_, airline0_.version as version0_0_ from Airline airline0_ where airline0_.AIRLINE_ID=?
Hibernate: select airline0_.AIRLINE_ID as AIRLINE1_0_0_, airline0_.AIRLINE_CODE as AIRLINE2_0_0_, airline0_.AIRLINE_NAME as AIRLINE3_0_0_, airline0_.version as version0_0_ from Airline airline0_ where airline0_.AIRLINE_ID=?
04:25:29.680 [later] DEBUG o.h.c.DriverManagerConnectionProvider - created connection to: jdbc:mysql://localhost:3306/test, Isolation Level: 4
04:25:29.681 [later] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: false
04:25:29.681 [later] DEBUG org.hibernate.loader.Loader - loading entity: [tryouts.one_to_many.Airline#1]
04:25:29.681 [later] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 1)
04:25:29.681 [later] DEBUG org.hibernate.SQL - select airline0_.AIRLINE_ID as AIRLINE1_0_0_, airline0_.AIRLINE_CODE as AIRLINE2_0_0_, airline0_.AIRLINE_NAME as AIRLINE3_0_0_, airline0_.version as version0_0_ from Airline airline0_ where airline0_.AIRLINE_ID=?
Hibernate: select airline0_.AIRLINE_ID as AIRLINE1_0_0_, airline0_.AIRLINE_CODE as AIRLINE2_0_0_, airline0_.AIRLINE_NAME as AIRLINE3_0_0_, airline0_.version as version0_0_ from Airline airline0_ where airline0_.AIRLINE_ID=?
04:25:29.682 [later] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
04:25:29.682 [earlier] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
04:25:29.683 [later] DEBUG org.hibernate.loader.Loader - result row: EntityKey[tryouts.one_to_many.Airline#1]
04:25:29.683 [earlier] DEBUG org.hibernate.loader.Loader - result row: EntityKey[tryouts.one_to_many.Airline#1]
04:25:29.687 [later] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 2)
04:25:29.687 [earlier] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 2)
04:25:29.687 [later] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
04:25:29.687 [earlier] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
04:25:29.688 [later] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [tryouts.one_to_many.Airline#1]
04:25:29.689 [earlier] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [tryouts.one_to_many.Airline#1]
04:25:29.695 [earlier] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [tryouts.one_to_many.Airline#1]
04:25:29.695 [later] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [tryouts.one_to_many.Airline#1]
04:25:29.695 [earlier] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
04:25:29.695 [later] DEBUG o.h.e.StatefulPersistenceContext - initializing non-lazy collections
04:25:29.695 [earlier] DEBUG org.hibernate.loader.Loader - done entity load
04:25:29.695 [later] DEBUG org.hibernate.loader.Loader - done entity load
getVersion in 53in earlier
getVersion in 53in later
getVersion in 53in earlier
04:25:31.697 [earlier] DEBUG o.h.transaction.JDBCTransaction - commit
04:25:31.697 [earlier] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
04:25:31.699 [earlier] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
04:25:31.704 [earlier] DEBUG org.hibernate.engine.Collections - Collection found: [tryouts.one_to_many.Airline.airlineFlights#1], was: [tryouts.one_to_many.Airline.airlineFlights#1] (uninitialized)
04:25:31.704 [earlier] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
04:25:31.704 [earlier] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections
04:25:31.705 [earlier] DEBUG org.hibernate.pretty.Printer - listing entities:
04:25:31.705 [earlier] DEBUG org.hibernate.pretty.Printer - tryouts.one_to_many.Airline{airlineFlights=<uninitialized>, airlineCode=asdasd234phle, airlineName=Jet Airways, airlineId=1, version=53}
04:25:31.707 [earlier] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
04:25:31.707 [earlier] DEBUG org.hibernate.SQL - update Airline set AIRLINE_CODE=?, version=? where AIRLINE_ID=? and version=?
Hibernate: update Airline set AIRLINE_CODE=?, version=? where AIRLINE_ID=? and version=?
04:25:31.708 [earlier] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
04:25:31.711 [earlier] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
04:25:31.711 [earlier] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
04:25:31.711 [earlier] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
getVersion in 53in later
04:27:09.695 [later] DEBUG o.h.transaction.JDBCTransaction - commit
04:27:09.696 [later] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
04:27:09.696 [later] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
04:27:09.696 [later] DEBUG org.hibernate.engine.Collections - Collection found: [tryouts.one_to_many.Airline.airlineFlights#1], was: [tryouts.one_to_many.Airline.airlineFlights#1] (uninitialized)
04:27:09.696 [later] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
04:27:09.696 [later] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 1 collections
04:27:09.696 [later] DEBUG org.hibernate.pretty.Printer - listing entities:
04:27:09.696 [later] DEBUG org.hibernate.pretty.Printer - tryouts.one_to_many.Airline{airlineFlights=<uninitialized>, airlineCode=asdasdbaadmain, airlineName=Jet Airways, airlineId=1, version=53}
04:27:09.697 [later] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
04:27:09.697 [later] DEBUG org.hibernate.jdbc.ConnectionManager - aggressively releasing JDBC connection
04:27:09.697 [later] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]

Answer 1

What's happening here is a case of dirty checking helping you out when you don't expect. I bet the original value of airlineCode is asdasdbaadmain, the same as you set in the 'later' thread.

Hibernate has a process called dirty checking, where it checks each field to see if it's been modified from the originally loaded state. In this case, you didn't change anything. No unchanged fields means no update, no SQL executed, no version conflict, and thus no exception.

The fact that you get the exception if you call session.evict() is due to the fact that if you've evicted the entity from the Session then there is nothing to dirty check against, and so Hibernate is forced to write to the database.