db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From dag.wan...@oracle.com (Dag H. Wanvik)
Subject Re: Working on adding a test case which will reliably run into sequence contention problem
Date Sat, 01 Oct 2011 00:53:15 GMT

I think it is reasonable that we mostly see timeouts here. I made another
version of the program that just lets threads allocate values from a
SEQUENCE back-to-back [2] and ran it this way:

  java -cp $CLASSPATH:. -Dderby.locks.waitTimeout=3
  -Dderby.locks.deadlockTimeout=2 -Dderby.language.sequence.preallocator=5
  DERBY4437Sequence 200 200000

with this [1] small patch to DataDictionaryImpl to count the number of times
another thread sneaks past the thread doing allocation, which is the
case leading up to the special contention event
(LANG_TOO_MUCH_CONTENTION_ON_SEQUENCE or the timeout exception after
DERBY-5426). 
Normally, under contention, the timeout will happen when calling
this line in SequenceUpdate:
     
***> if ( updateCurrentValueOnDisk( new Long( currentValue ), 
          new Long( lastAllocatedValue ) ) )
     {
        _sequenceGenerator.allocateNewRange( currentValue, numberOfValuesAllocated );
     }

If the code gets past this call, it means somebody snuck past us and
allocated a new range first. Then we check the time passed: the first
time around "startTime" is null, so we try again. For the special
contention event we need to get snuck past at least twice *without
seeing lock timeout*, but still having to wait quite a bit. E.g. first
time around we wait 0.6 timeouts but get snuck past, then we note the time,
try again, and wait, say 0.7 timeouts, then get snuck past a second
time. Now, we compare the time spent and see 1.3 timeout and we throw
(special contention event). This is not very likely:

My test registered the following numbers with the run arguments I used above:

  Total # of timeouts: 12278
  Total # of snucks: 49

I am not sure there is a reliable way to provoke this situation.

Thanks,
Dag

[1]
Index: java/engine/org/apache/derby/impl/sql/catalog/DataDictionaryImpl.java
===================================================================
--- java/engine/org/apache/derby/impl/sql/catalog/DataDictionaryImpl.java	(revision 1177483)
+++ java/engine/org/apache/derby/impl/sql/catalog/DataDictionaryImpl.java	(working copy)
@@ -10219,7 +10219,7 @@
              SYSSEQUENCESRowFactory.SYSSEQUENCES_CURRENT_VALUE
              );
     }
-    
+    public static long races;
 	/**
 	 * Set the current value of an ANSI/ISO sequence or identity column. This method does not
perform
      * any sanity checking but assumes that the caller knows what they are doing. If the
@@ -10298,6 +10298,7 @@
             }
             else
             {
+                races++;
                 return false;
             }
         }


[2]
import java.sql.*;
import org.apache.derby.impl.sql.catalog.DataDictionaryImpl;
import java.util.concurrent.atomic.AtomicLong;

public class DERBY4437Sequence extends Thread {
    static AtomicLong timeouts = new AtomicLong(0);

    public static void main(String[] args) throws Exception {

    	int numberOfThreads = 1000;
		
		if (args.length != 2) {
            System.err.println("Legend: $0 <no of threads> <testduration>");
	    }

        numberOfThreads = Integer.parseInt(args[0]);
        DERBY4437Sequence initThreads[] =
			new DERBY4437Sequence[numberOfThreads];
		
		Connection conn = null;
        Class.forName("org.apache.derby.jdbc.EmbeddedDriver");
        conn =  DriverManager.getConnection(
                "jdbc:derby:DERBY4437DB;create=true");

        conn.setAutoCommit(false);

        Statement st  = conn.createStatement();
        st.executeUpdate(
            "create sequence myseq as int start with 1 no maxvalue cycle");
        conn.commit();
        conn.close();

        System.err.println("Get threads going");
		for (int i = 0; i < numberOfThreads; i++) {
			initThreads[i] = new DERBY4437Sequence(i);
			initThreads[i].start();
			sleep(1);
		}
        System.err.println("Done starting threads");

        Thread.sleep(Integer.parseInt(args[1]));
        System.err.println("Total # of timeouts: " + timeouts.get());
        System.err.println("Total # of snucks: " + DataDictionaryImpl.races);
        System.exit(0);
    }

    private int threadNumber;

    private PreparedStatement ps;
    private Connection conn;

    DERBY4437Sequence(int threadNumber) throws Exception {

		this.threadNumber = threadNumber;

        conn =  DriverManager.getConnection(
        		"jdbc:derby:DERBY4437DB");

        conn.setAutoCommit(false);
        ps = conn.prepareStatement("values next value for myseq");
		System.err.println("Created ps for thread number" + threadNumber);
    }

	public void run() {
		System.err.println(threadNumber + " is now running");
    	try {
            int cnt = 0;
            
            while (true) {
    			ResultSet rs = ps.executeQuery();
                try {
                    rs.next();
                } catch (SQLException e) {
                    if ("40XL1".equals(e.getSQLState())) {
                        // lock timeout, try again
                        rs.close();
                        timeouts.incrementAndGet();
                        continue;
                    }
                }

                int got = rs.getInt(1);
                rs.close();

    			if (cnt++ % 100000 == 0) {
    				System.err.println(
                        "Thread " + threadNumber + " got " +
                        (cnt - 1) + " sequence numbers");
    				conn.commit();
    			}
            }
    	} catch (Exception ex)  {
    		System.err.println("error in thread " + threadNumber);
    		ex.printStackTrace();
    	}
		System.err.println(threadNumber + " is done running");
	}
}

Mime
View raw message