Attached are a couple of test programs to reproduce the error with Derby
10.4.1.3 in embedded mode:
CompressDBTest1.java - tries to read a table while it is being compressed.
The select statement errors out with the following error:
java.sql.SQLException: Container 2,192 not found.
Subsequent SELECTs with a brand new connection also fail with a little bit
different error:
The conglomerate (2,192) requested does not exist.
CompressDBTest2.java - tries to insert data into a table while it is being
compressed. The insert errors out eventually with the following error:
A lock could not be obtained due to a deadlock, cycle of locks and waiters
is:
Lock : TABLE, TEST, Tablelock
Waiting XID : {236439, IX} , APP, insert into test values(?, ?, ?, ?, ?)
Granted XID : {234342, X}
Lock : ROW, SYSCONGLOMERATES, (5,14)
Waiting XID : {234342, X} , APP, alter table "APP"."TEST" compress
sequential
Granted XID : {234342, S} , {236439, S}
. The selected victim is XID : 236439.
What the test classes do:
Both classes first create a database named test under the current working
directory if a directory named test does not already exist. Then a table
named test is created and populated with 100,000 random records. Two threads
are started then with the first one repeatedly compressing the test table
and the second one repeatedly executing a DML statement. If the DML
statement errors out, the compression thread will be stopped. Finally the
database is shutdown. The standard output of the program goes to stdout.log
and standard error goes to stderr.log in the current working directory.
In my tests, it did not take more than 10 to 20 seconds to see the error(s).
Hope this helps. Please let me know if you have any questions or need
additional information.
On a side note, no exceptions or errors are reported in the derby.log. All I
see is the booting info and the shutdown info.
Regards,
Sai Pullabhotla
www.jMethods.com
On Fri, Jun 5, 2009 at 2:44 PM, Kathey Marsden
<[email protected]>wrote:
> Sai Pullabhotla wrote:
>
>> Since the customer restarted the app, by the time we got the derby.log, it
>> was empty (I guess the log is overwritten everytime?).
>>
> It does unless unless you set this property:
> http://db.apache.org/derby/docs/10.5/ref/rrefproper13217.html#rrefproper13217
>
>> I will try to see if I can reproduce the error here and send you any
>> additional logs.
>>
>> It looks like you have a good understanding of what was going on at the
> time, so hopefully you can come up with a reproduction. Even if you
> cannot, post what you have tried and perhaps someone can offer some
> suggestions or tweak it to pop the bug.
>
> Kathey
>
import java.io.File;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
import java.io.PrintStream;
import java.sql.CallableStatement;
import java.sql.Connection;
import java.sql.Date;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.sql.Timestamp;
import java.text.SimpleDateFormat;
import java.util.Random;
/**
* A test program for reproducing the concurrency issue with database
* compression procedure and DML statements.
*
* @author Sai Pullabhotla
* @version $Revision: 1.1 $
*
*/
public class CompressDBTest1 {
/**
* A random number generator to populate random data
*/
private static Random random = null;
/**
* Database URL
*/
private static final String DB_URL = "jdbc:derby:test";
/**
* Flag to indicate if either of the threads errored out.
*/
private static boolean error = false;
/**
* Entry point for the program.
*
* @param args
* command line arguments
* @throws ClassNotFoundException
* propagated
* @throws SQLException
* propagated
* @throws FileNotFoundException
* propagated
*/
public static void main(String[] args) throws ClassNotFoundException,
SQLException, FileNotFoundException {
System.out.println("stdout is being redirected to stdout.log and stderr is being redirected to stderr.log. ");
FileOutputStream stdout = new FileOutputStream("stdout.log");
System.setOut(new PrintStream(stdout));
FileOutputStream stderr = new FileOutputStream("stderr.log");
System.setErr(new PrintStream(stderr));
Thread.currentThread().setName("MainThread ");
init();
File dbDir = new File("test");
if (!dbDir.exists()) {
createDB();
populateTable();
}
else {
log("Database 'test' already exists");
}
CompressionThread compressionThread = new CompressionThread();
compressionThread.start();
SelectThread selectThread = new SelectThread();
selectThread.start();
try {
compressionThread.join();
selectThread.join();
}
catch (InterruptedException exp) {
log(exp);
}
shutdownDB();
}
/**
* Initializes this program.
*
* @throws ClassNotFoundException
* propagated
*/
private static void init() throws ClassNotFoundException {
log("Initializing...");
Class.forName("org.apache.derby.jdbc.EmbeddedDriver");
random = new Random();
}
/**
* Creates a database named test under the current working directory. Also
* creates a table called test under the database.
*
* @throws SQLException
* propagated
*/
private static void createDB() throws SQLException {
log("Creating database 'test'...");
Connection con = null;
Statement stmt = null;
try {
con = DriverManager.getConnection(DB_URL + ";create=true");
log("Database 'test' was created successfully");
log("Creating table 'test'...");
String sql = "create table test(col_int integer, col_char char(20), "
+ "col_decimal decimal(10, 2), col_date date, col_timestamp timestamp)";
stmt = con.createStatement();
stmt.executeUpdate(sql);
log("Table 'test' was created successfully");
}
finally {
if (stmt != null) {
stmt.close();
}
if (con != null) {
con.close();
}
}
}
/**
* Populates the test table with random data.
*
* @throws SQLException
* propagated
*/
private static void populateTable() throws SQLException {
log("Populating table test with random data...");
Connection con = DriverManager.getConnection(DB_URL);
String sql = "insert into test values(?, ?, ?, ?, ?)";
PreparedStatement stmt = con.prepareStatement(sql);
int count = 0;
int rowsNeeded = 100000;
int updateCount = 0;
while (count++ < rowsNeeded) {
stmt.setInt(1, getRandomInt());
stmt.setString(2, getRandomString(20));
stmt.setDouble(3, getRandomDecimal());
stmt.setDate(4, new Date(System.currentTimeMillis()));
stmt.setTimestamp(5, new Timestamp(System.currentTimeMillis()));
updateCount += stmt.executeUpdate();
}
stmt.close();
con.close();
log(updateCount + " record(s) were inserted");
}
/**
* Returns a random integer.
*
* @return a random integer.
*/
private static int getRandomInt() {
return random.nextInt();
}
/**
* Returns a random string of given length.
*
* @param length
* the length of the string
* @return a random string of given length.
*/
private static String getRandomString(int length) {
StringBuilder buffer = new StringBuilder(length);
for (int i = 0; i < length; i++) {
int ch = random.nextInt(26);
ch += 65;
buffer.append((char) ch);
}
return buffer.toString();
}
/**
* Returns a random decimal number of size (10, 2).
*
* @return a random decimal number of size (10, 2).
*/
private static double getRandomDecimal() {
int val = random.nextInt(99999999);
int precision = random.nextInt(99);
return val + (precision / 100.0);
}
/**
* Attempts to shutdown the database.
*/
private static void shutdownDB() {
log("Shutting down the databse...");
try {
DriverManager.getConnection(DB_URL + ";shutdown=true");
}
catch (SQLException exp) {
log(exp);
}
}
/**
* A thread the constantly compresses the test table.
*
* @author Sai Pullabhotla
* @version $Revision: 1.1 $
*
*/
private static class CompressionThread extends Thread {
/**
* Creates a new instance of <code>CompressionThread</code>.
*/
public CompressionThread() {
super("CompressionThread");
}
@Override
public void run() {
Connection con = null;
CallableStatement stmt = null;
for (int i = 0; i < 1000; i++) {
if (error) {
break;
}
try {
con = DriverManager.getConnection(DB_URL);
stmt = con.prepareCall("call SYSCS_UTIL.SYSCS_COMPRESS_TABLE(?, ?, ?)");
log("Comressing table 'TEST'...");
stmt.setString(1, "APP");
stmt.setString(2, "TEST");
stmt.setShort(3, (short) 1);
stmt.execute();
log("Table 'TEST' was compressed successfully");
}
catch (SQLException exp) {
error = true;
log(exp);
}
finally {
if (stmt != null) {
try {
stmt.close();
}
catch (SQLException exp) {
log(exp);
}
}
if (con != null) {
try {
con.close();
}
catch (SQLException exp) {
log(exp);
}
}
}
}
}
}
/**
* A thread for querying the database table while it is being compressed.
*
* @author Sai Pullabhotla
* @version $Revision: 1.1 $
*
*/
private static class SelectThread extends Thread {
/**
* Creates a new instance of <code>SelectThread</code>.
*/
public SelectThread() {
super("SelectThread ");
}
@Override
public void run() {
Connection con = null;
PreparedStatement stmt = null;
final String sql = "select * from test where col_int=?";
for (int i = 0; i < 1000; i++) {
// if (error) {
// break;
// }
try {
con = DriverManager.getConnection(DB_URL);
stmt = con.prepareStatement(sql);
int searchFor = getRandomInt();
stmt.setInt(1, searchFor);
ResultSet rs = stmt.executeQuery();
if (!rs.next()) {
log("No record(s) found matching the ID: " + searchFor);
}
else {
log("At least one record exists with ID: " + searchFor);
}
rs.close();
}
catch (SQLException exp) {
log(exp);
error = true;
}
finally {
if (stmt != null) {
try {
stmt.close();
}
catch (SQLException exp) {
log(exp);
}
}
if (con != null) {
try {
con.close();
}
catch (SQLException exp) {
log(exp);
}
}
}
}
}
}
/**
* Logs the given message with the timestamp information and the thread that
* called for this message to be logged.
*
* @param message
* the message to be logged.
*/
private static synchronized void log(String message) {
SimpleDateFormat formatter = new SimpleDateFormat(
"MM/dd/yyyy HH:mm:ss.SSS");
System.out.print(formatter.format(new java.util.Date()));
System.out.print(" ");
System.out.print(Thread.currentThread().getName());
System.out.print(" ");
System.out.print(message);
System.out.println();
}
/**
* Logs the given message with the timestamp information and the thread that
* called for this message to be logged.
*
* @param t
* the exception to be logged
*/
private static synchronized void log(Throwable t) {
log(t.getMessage());
log("See the stderr.log for the stacktrace of the above exception");
t.printStackTrace();
}
}
import java.io.File;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
import java.io.PrintStream;
import java.sql.CallableStatement;
import java.sql.Connection;
import java.sql.Date;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.SQLException;
import java.sql.Statement;
import java.sql.Timestamp;
import java.text.SimpleDateFormat;
import java.util.Random;
/**
* A test program for reproducing the concurrency issue with database
* compression procedure and DML statements.
*
* @author Sai Pullabhotla
* @version $Revision: 1.1 $
*
*/
public class CompressDBTest2 {
/**
* A random number generator to populate random data
*/
private static Random random = null;
/**
* Database URL
*/
private static final String DB_URL = "jdbc:derby:test";
/**
* Flag to indicate if the DML thread errored out.
*/
private static boolean error = false;
/**
* Entry point for the program.
*
* @param args
* command line arguments
* @throws ClassNotFoundException
* propagated
* @throws SQLException
* propagated
* @throws FileNotFoundException
* propagated
*/
public static void main(String[] args) throws ClassNotFoundException,
SQLException, FileNotFoundException {
System.out.println("stdout is being redirected to stdout.log and stderr is being redirected to stderr.log. ");
FileOutputStream stdout = new FileOutputStream("stdout.log");
System.setOut(new PrintStream(stdout));
FileOutputStream stderr = new FileOutputStream("stderr.log");
System.setErr(new PrintStream(stderr));
Thread.currentThread().setName("MainThread ");
init();
File dbDir = new File("test");
if (!dbDir.exists()) {
createDB();
populateTable();
}
else {
log("Database 'test' already exists");
}
CompressionThread compressionThread = new CompressionThread();
compressionThread.start();
InsertThread selectThread = new InsertThread();
selectThread.start();
try {
compressionThread.join();
selectThread.join();
}
catch (InterruptedException exp) {
log(exp);
}
shutdownDB();
}
/**
* Initializes this program.
*
* @throws ClassNotFoundException
* propagated
*/
private static void init() throws ClassNotFoundException {
log("Initializing...");
Class.forName("org.apache.derby.jdbc.EmbeddedDriver");
random = new Random();
}
/**
* Creates a database named test under the current working directory. Also
* creates a table called test under the database.
*
* @throws SQLException
* propagated
*/
private static void createDB() throws SQLException {
log("Creating database 'test'...");
Connection con = null;
Statement stmt = null;
try {
con = DriverManager.getConnection(DB_URL + ";create=true");
log("Database 'test' was created successfully");
log("Creating table 'test'...");
String sql = "create table test(col_int integer, col_char char(20), "
+ "col_decimal decimal(10, 2), col_date date, col_timestamp timestamp)";
stmt = con.createStatement();
stmt.executeUpdate(sql);
log("Table 'test' was created successfully");
}
finally {
if (stmt != null) {
stmt.close();
}
if (con != null) {
con.close();
}
}
}
/**
* Populates the test table with random data.
*
* @throws SQLException
* propagated
*/
private static void populateTable() throws SQLException {
log("Populating table test with random data...");
Connection con = DriverManager.getConnection(DB_URL);
String sql = "insert into test values(?, ?, ?, ?, ?)";
PreparedStatement stmt = con.prepareStatement(sql);
int count = 0;
int rowsNeeded = 100000;
int updateCount = 0;
while (count++ < rowsNeeded) {
stmt.setInt(1, getRandomInt());
stmt.setString(2, getRandomString(20));
stmt.setDouble(3, getRandomDecimal());
stmt.setDate(4, new Date(System.currentTimeMillis()));
stmt.setTimestamp(5, new Timestamp(System.currentTimeMillis()));
updateCount += stmt.executeUpdate();
}
stmt.close();
con.close();
log(updateCount + " record(s) were inserted");
}
/**
* Returns a random integer.
*
* @return a random integer.
*/
private static int getRandomInt() {
return random.nextInt();
}
/**
* Returns a random string of given length.
*
* @param length
* the length of the string
* @return a random string of given length.
*/
private static String getRandomString(int length) {
StringBuilder buffer = new StringBuilder(length);
for (int i = 0; i < length; i++) {
int ch = random.nextInt(26);
ch += 65;
buffer.append((char) ch);
}
return buffer.toString();
}
/**
* Returns a random decimal number of size (10, 2).
*
* @return a random decimal number of size (10, 2).
*/
private static double getRandomDecimal() {
int val = random.nextInt(99999999);
int precision = random.nextInt(99);
return val + (precision / 100.0);
}
/**
* Attempts to shutdown the database.
*/
private static void shutdownDB() {
log("Shutting down the databse...");
try {
DriverManager.getConnection(DB_URL + ";shutdown=true");
}
catch (SQLException exp) {
log(exp);
}
}
/**
* A thread the constantly compresses the test table.
*
* @author Sai Pullabhotla
* @version $Revision: 1.1 $
*
*/
private static class CompressionThread extends Thread {
/**
* Creates a new instance of <code>CompressionThread</code>.
*/
public CompressionThread() {
super("CompressionThread");
}
@Override
public void run() {
Connection con = null;
CallableStatement stmt = null;
for (int i = 0; i < 1000; i++) {
if (error) {
break;
}
try {
con = DriverManager.getConnection(DB_URL);
stmt = con.prepareCall("call SYSCS_UTIL.SYSCS_COMPRESS_TABLE(?, ?, ?)");
log("Comressing table 'TEST'...");
stmt.setString(1, "APP");
stmt.setString(2, "TEST");
stmt.setShort(3, (short) 1);
stmt.execute();
log("Table 'TEST' was compressed successfully");
}
catch (SQLException exp) {
error = true;
log(exp);
}
finally {
if (stmt != null) {
try {
stmt.close();
}
catch (SQLException exp) {
log(exp);
}
}
if (con != null) {
try {
con.close();
}
catch (SQLException exp) {
log(exp);
}
}
}
}
}
}
/**
* A thread for inserting records into the database table while it is being
* compressed.
*
* @author Sai Pullabhotla
* @version $Revision: 1.1 $
*
*/
private static class InsertThread extends Thread {
/**
* Creates a new instance of <code>SelectThread</code>.
*/
public InsertThread() {
super("InsertThread ");
}
@Override
public void run() {
try {
populateTable();
}
catch (SQLException exp) {
error = true;
log(exp);
}
}
}
/**
* Logs the given message with the timestamp information and the thread that
* called for this message to be logged.
*
* @param message
* the message to be logged.
*/
private static synchronized void log(String message) {
SimpleDateFormat formatter = new SimpleDateFormat(
"MM/dd/yyyy HH:mm:ss.SSS");
System.out.print(formatter.format(new java.util.Date()));
System.out.print(" ");
System.out.print(Thread.currentThread().getName());
System.out.print(" ");
System.out.print(message);
System.out.println();
}
/**
* Logs the given message with the timestamp information and the thread that
* called for this message to be logged.
*
* @param t
* the exception to be logged
*/
private static synchronized void log(Throwable t) {
log(t.getMessage());
log("See the stderr.log for the stacktrace of the above exception");
t.printStackTrace();
}
}
