db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mamta A. Satoor (Commented) (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (DERBY-5638) intermittent test failure in test_05_ClobNegative when running full largedata._Suite; LobLimitsTestjava.sql.SQLException: Table/View 'BLOBTBL' already exists in Schema 'APP'.
Date Tue, 20 Mar 2012 23:17:38 GMT

    [ https://issues.apache.org/jira/browse/DERBY-5638?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13233931#comment-13233931
] 

Mamta A. Satoor commented on DERBY-5638:
----------------------------------------

The large data test ran into out of disk space problem in one out of the 2 runs since the
checkin on the March 15th. After clearing up the space by deleting few old runs, the test
ran fine the 2nd time.

It will be good idea to reduce the size of the wombat database after every large data suite
has finished thus successful runs will not occupy too much disk space. I went with Knut's
recommendation to add truncate table as part of the cleanup in deleteTable() method. I kept
the delete from table code too because delete follows a different code path than truncate
and it will be good for us to test both code paths in case of large data testing. The deleteTable()
method looks as follows in my codeline
    private void deleteTable(String table,
            int expectedRows) throws SQLException {
    	Statement s = createStatement();
        //Keep the delete call to exercise delete of long blobs and clobs.
    	// This is a separate code path through Derby compared to truncate
    	// table code path.
        int count = s.executeUpdate(
                "DELETE FROM " + JDBC.escape(table));
        //Adding truncate call which will give back the disk space being 
        // used by the table at commit time rather than wait for test 
        // infrastructure to drop the table.
        s.executeUpdate("TRUNCATE TABLE " + JDBC.escape(table));
        commit();
        verifyTest(count, expectedRows, "Rows deleted =");
    }

What I found with this change is that the wombat/log directory is much larger than it was
without the truncate table call.

log directory looks as follows with the svn codeline(ie without the truncate table call)
$ ls -l log
total 3702
----------+ 1 mamta mkgroup      48 Mar 14 16:56 log.ctrl
----------+ 1 mamta mkgroup 2738408 Mar 14 16:56 log440.dat
----------+ 1 mamta mkgroup 1048576 Mar 14 19:00 log441.dat
----------+ 1 mamta mkgroup      48 Mar 14 16:56 logmirror.ctrl

log directory with large data suite run with truncate table call as shown in the deleteTable
method looks as follows
$ ls -l log
total 312254
----------+ 1 mamta mkgroup       48 Mar 19 17:02 log.ctrl
----------+ 1 mamta mkgroup 26765701 Mar 19 17:00 log416.dat
----------+ 1 mamta mkgroup 33559814 Mar 19 17:00 log417.dat
----------+ 1 mamta mkgroup 33560037 Mar 19 17:01 log418.dat
----------+ 1 mamta mkgroup 33791143 Mar 19 17:01 log419.dat
----------+ 1 mamta mkgroup 31539171 Mar 19 17:01 log420.dat
----------+ 1 mamta mkgroup  6268114 Mar 19 17:01 log421.dat
----------+ 1 mamta mkgroup  3071813 Mar 19 17:01 log422.dat
----------+ 1 mamta mkgroup 31544805 Mar 19 17:01 log423.dat
----------+ 1 mamta mkgroup 33529672 Mar 19 17:01 log424.dat
----------+ 1 mamta mkgroup 33503893 Mar 19 17:01 log425.dat
----------+ 1 mamta mkgroup 33768332 Mar 19 17:02 log426.dat
----------+ 1 mamta mkgroup 17774482 Mar 19 17:02 log427.dat
----------+ 1 mamta mkgroup  1048576 Mar 19 18:47 log428.dat
----------+ 1 mamta mkgroup       48 Mar 19 17:02 logmirror.ctrl

I talked to Mike about the change in number of files in log directory and he mentioned that
if we actually look at the number in the log file names(for eg for428.dat), we will see that
Derby didn't have to write as much to the log when we use truncate table which is a good sign.
As can be seen above, with truncate table, the last log files name is log428.dat whereas log
file name with trunk codeline run is log441.dat  

The reason we see large number of log files with truncate table is that probably a checkpoint
was not issued. Checkpoints are issued periodically and among other things, it;s frequency
also depends on how many log files have been written so far.

I tried connecting to the wombat directory with large number of log files through ij and after
getting out of ij, I saw that there were only 3 log files left in log directory as shown below
$ ls -l
total 1026
----------+ 1 mamta mkgroup      48 Mar 20 10:20 log.ctrl
----------+ 1 mamta mkgroup 1048576 Mar 20 10:20 log428.dat
----------+ 1 mamta mkgroup      48 Mar 20 10:20 logmirror.ctrl

The reason for reduction in number of log files is as part of booting up wombat through ij,
we applied all the left over log files to the database and hence as part of recovery, the
log files were deleted since they are not needed any more.

Based on this experiment, in addition to having truncate table in deleteTable() method, I
plan on adding a test fixture to LobLimitsTest class and that test fixture will just shutodwn
the databases. As part of the shutdown, the logs will get applied and hence at the end of
the suite, the size of the wombat database will be much smaller and there won't be left over
huge log files left behind after a successful run.

Once I have the tests running successfully with this change and verify that log directory
is indeed much smaller, i will post a patch.
                
> intermittent test failure in test_05_ClobNegative when running full largedata._Suite;
LobLimitsTestjava.sql.SQLException: Table/View 'BLOBTBL' already exists in Schema 'APP'.
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: DERBY-5638
>                 URL: https://issues.apache.org/jira/browse/DERBY-5638
>             Project: Derby
>          Issue Type: Bug
>          Components: Test
>    Affects Versions: 10.9.0.0
>         Environment: ibm 1.6 sr9 fp1, Seen on Windows XP/VMWare, and Linux (CentOS)/VMWare
>            Reporter: Myrna van Lunteren
>            Assignee: Mamta A. Satoor
>              Labels: derby_triage10_9
>         Attachments: CompleteRunallWithPrintlnTrace.out, DERBY5638_patch1_diff.txt, DERBY5638_patch2_diff.txt,
derbyFailed.log, derbyPass.log, derbyWithRollbackInTest_05.log, derbyallFailWithPrintlnTrace.log,
runallForSuccessfulLargeDataRun.out, runallWithPrintlnTrace.out
>
>
> I've seen the following failure when running the largedata suite:
> (emb)largedata.Derby5624Test.testDERBY_5624 used 518403 ms .
> (emb)largedata.LobLimitsTest.test_01_Blob used 2422 ms .
> (emb)largedata.LobLimitsTest.test_02_BlobNegative used 31 ms .
> (emb)largedata.LobLimitsTest.test_03_Clob1 used 2375 ms .
> (emb)largedata.LobLimitsTest.test_04_Clob2 used 3234 ms .
> (emb)largedata.LobLimitsTest.test_05_ClobNegative used 516 ms .
> (net)largedata.LobLimitsTest.test_01_Blob used 5360 ms .
> (net)largedata.LobLimitsTest.test_02_BlobNegative used 32 ms .
> (net)largedata.LobLimitsTest.test_03_Clob1 used 2078 ms .
> (net)largedata.LobLimitsTest.test_04_Clob2 used 2390 ms .
> (net)largedata.LobLimitsTest.test_05_ClobNegative used 938 ms .
> (emb)largedata.LobLimitsTest.test_01_Blob used 9188238 ms .
> (emb)largedata.LobLimitsTest.test_02_BlobNegative used 109 ms .
> (emb)largedata.LobLimitsTest.test_03_Clob1 used 8116714 ms .
> (emb)largedata.LobLimitsTest.test_04_Clob2 used 2164002 ms .
> (emb)largedata.LobLimitsTest.test_05_ClobNegative used 685745 ms E
> Time: 22,320.138
> There was 1 error:
> 1) LobLimitsTestjava.sql.SQLException: Table/View 'BLOBTBL' already exists in Schema
'APP'.
> 	at org.apache.derby.client.am.SQLExceptionFactory40.getSQLException(Unknown Source)
> 	at org.apache.derby.client.am.SqlException.getSQLException(Unknown Source)
> 	at org.apache.derby.client.am.Statement.execute(Unknown Source)
> 	at org.apache.derbyTesting.functionTests.tests.largedata.LobLimitsTest.setupTables(LobLimitsTest.java:107)
> 	at org.apache.derbyTesting.functionTests.tests.largedata.LobLimitsTest$1.decorateSQL(LobLimitsTest.java:141)
> 	at org.apache.derbyTesting.junit.CleanDatabaseTestSetup.setUp(CleanDatabaseTestSetup.java:112)
> 	at junit.extensions.TestSetup$1.protect(TestSetup.java:20)
> 	at junit.extensions.TestSetup.run(TestSetup.java:25)
> 	at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
> 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> 	at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> 	at junit.extensions.TestSetup.run(TestSetup.java:25)
> 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> 	at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> 	at junit.extensions.TestSetup.run(TestSetup.java:25)
> 	at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
> 	at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> 	at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> 	at junit.extensions.TestSetup.run(TestSetup.java:25)
> Caused by: org.apache.derby.client.am.SqlException: Table/View 'BLOBTBL' already exists
in Schema 'APP'.
> 	at org.apache.derby.client.am.Statement.completeSqlca(Unknown Source)
> 	at org.apache.derby.client.am.Statement.completeExecuteImmediate(Unknown Source)
> 	at org.apache.derby.client.net.NetStatementReply.parseEXCSQLIMMreply(Unknown Source)
> 	at org.apache.derby.client.net.NetStatementReply.readExecuteImmediate(Unknown Source)
> 	at org.apache.derby.client.net.StatementReply.readExecuteImmediate(Unknown Source)
> 	at org.apache.derby.client.net.NetStatement.readExecuteImmediate_(Unknown Source)
> 	at org.apache.derby.client.am.Statement.readExecuteImmediate(Unknown Source)
> 	at org.apache.derby.client.am.Statement.flowExecute(Unknown Source)
> 	at org.apache.derby.client.am.Statement.executeX(Unknown Source)
> 	... 26 more
> Unfortunately, when this happens, there seems to be no 'fail' directory created. The
derby.log in the system directory looks very innocent (just some start up and shutting down
of the database), and the serverConsoleOutput.log only has the typical 'failed to find db
'wombat' messages'.
> Note, when this happens, the suite exits, so that instead of the expected 20 (or 21 on
windows, see DERBY-5624 for reason for skipping on Linux default installs with 1024 max open
files) we only get 15 (or 16) tests run - if the test doesn't fail it goes on to run the last
5 fixtures again for network server.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message