SELECT before ALTER TABLE hides new column in subsequent SELECT in single-threaded test case

Viewed 232

Step-by-step

  1. Android Studio Bumblebee -> File -> New -> New Project -> Empty Activity -> Finish (use defaults)

  2. Open app/src/androidTest/java/com/example/myapplication/ExampleInstrumentedTest.kt and add the following test and then run it on e.g. an API level 30 emulator:

    @org.junit.Test
    fun visibility_of_column_after_select_then_alter_then_select_again() {
        val appContext = androidx.test.platform.app.InstrumentationRegistry.getInstrumentation().targetContext

        // Use a fresh DB each time
        val dbPath = appContext.getDatabasePath(java.util.UUID.randomUUID().toString())
        val db = android.database.sqlite.SQLiteDatabase.openDatabase(
            dbPath,
            android.database.sqlite.SQLiteDatabase.OpenParams.Builder()
                .addOpenFlags(android.database.sqlite.SQLiteDatabase.CREATE_IF_NECESSARY)
                .build()
        )

        // Query 1: CREATE TABLE
        db.execSQL("CREATE TABLE some_table (some_column TEXT)")

        // Query 2: SELECT all columns (to assert on index of new_column)
        assertColumnIndex(db, "new_column", -1)

        // Query 3: ALTER TABLE to add column
        db.execSQL("ALTER TABLE some_table ADD new_column TEXT")

        // Query 4: SELECT all columns again (to assert on index of new_column)
        assertColumnIndex(db, "new_column", 1)
    }

    private fun assertColumnIndex(db: android.database.sqlite.SQLiteDatabase, columnName: String, expectedIndex: Int) {
        val cursor = db.query("some_table", null, null, null, null, null, null)
        org.junit.Assert.assertEquals(expectedIndex, cursor.getColumnIndex(columnName))
        cursor.close()
    }

Expected result

The test passes.

Actual result

The test fails when asserting on that "new_column" index is 1 after Query 4. It is -1, also known as "not found". Which is strange, because we added it right before.

However, the test PASS if I do just one of the following two things:

  • A. Put // in front of Query 2, i.e. stop issuing that SELECT query. I find this very strange.

  • B. Add .addOpenFlags(SQLiteDatabase.ENABLE_WRITE_AHEAD_LOGGING) to the OpenParams.Builder. This is less strange, but does not make it easier to understand why A. make a difference.

Question

Why does A. make the test pass?

1 Answers

Or at least understand why WAL is needed in this case.

Tested this in Kotlin and Java and the result is the same, although the new column is added (according to the schema aka sqlite_master) the cursor doesn't appear to be aware but is in WAL mode.

Unsure as to why, I suspect it might be the SQLite API.

but I would like a solution that does not require WAL.

One solution would be to not use alter but to drop the table and recreate it e.g.

    db.execSQL("DROP TABLE IF EXISTS some_table")
    db.execSQL("CREATE TABLE IF NOT EXISTS some_table (some_column TEXT, new_column TEXT)")

Another alternative is to close and then re-open the database, however this would be relatively resource expensive.

The following was used for testing various scenarios:-

For the Java testing (showing that the same happens with Java code) :-

class TestJava {

   static void test(Context context) {

      String dbpath = context.getDatabasePath(UUID.randomUUID().toString()).toString();
      SQLiteDatabase db = SQLiteDatabase.openOrCreateDatabase(dbpath,null);
      db.execSQL("CREATE TABLE some_table (some_column TEXT)");
      assertColumn(db,"new_column",1);
      db.execSQL("ALTER TABLE some_table ADD new_column TEXT NOT NULL DEFAULT 'x'");
      assertColumn(db,"new_column",1);
   }

   private static void assertColumn(SQLiteDatabase db, String columnName, int expectedIndex) {
      Cursor csr = db.query("some_table",null,null,null,null,null,null);
      int retrievedIndex = csr.getColumnIndex(columnName);
      Log.d("TESTINFO_JAVA","Expected = " + expectedIndex + " Retrieved = " + retrievedIndex);
      csr.close();
   }
}

The activity used to test :-

class MainActivity : AppCompatActivity() {
    override fun onCreate(savedInstanceState: Bundle?) {
        super.onCreate(savedInstanceState)
        setContentView(R.layout.activity_main)

        // Use a fresh DB each time
        val dbPath = this.getDatabasePath(UUID.randomUUID().toString())
        var db = SQLiteDatabase.openOrCreateDatabase(dbPath, null)
        //db.enableWriteAheadLogging()

        // Query 1: CREATE TABLE
        db.execSQL("CREATE TABLE some_table (some_column TEXT)")
        showSchemaForTable(db,"some_table","TESTINFO-001")

        // Query 2: SELECT all columns (to assert on index of new_column)
        assertColumnIndex(db, "new_column", -1)

        // Query 3: ALTER TABLE to add column
        db.execSQL("ALTER TABLE some_table ADD new_column TEXT")
        showSchemaForTable(db,"some_table","TESTINFO-002")
        assertColumnIndex(db, "new_column", 1)
        db.close()
        db = SQLiteDatabase.openDatabase(dbPath.toString(),null,SQLiteDatabase.OPEN_READWRITE)

        // Query 4: SELECT all columns again (to assert on index of new_column)
        assertColumnIndex(db, "new_column", 1)

        // Added to show working equivalent
        db.execSQL("DROP TABLE IF EXISTS some_table")
        db.execSQL("CREATE TABLE IF NOT EXISTS some_table (some_column TEXT, new_column TEXT)")
        showSchemaForTable(db,"some_table","TESTINFO-003")
        assertColumnIndex(db, "new_column", 1)
        TestJava.test(this)

    }

    private fun assertColumnIndex(db: SQLiteDatabase, columnName: String, expectedIndex: Int) {
        var cursor = db.query("some_table", null, null, null, null, null, null)
        var retrievedIndex = cursor.getColumnIndex(columnName)
        Log.d("TESTINFO", "Expected = ${expectedIndex} RetrievedIndex = ${retrievedIndex} columns in cursor are:-")
        for (cName in cursor.columnNames) {
            Log.d("TESTINFO","\tColumn Name is ${cName}")
        }
        cursor.close()
    }

    @SuppressLint("Range")
    private fun showSchemaForTable(db: SQLiteDatabase, tableName: String, tag: String) {
        var cursor= db.rawQuery("SELECT * FROM sqlite_master WHERE name = '${tableName}'",null)
        while (cursor.moveToNext()) {
            Log.d(tag,"Table is ${tableName} SQL(schema) is ${cursor.getString(cursor.getColumnIndex("sql"))}")
        }
    }
}

The Log shows :-

2022-03-05 14:33:17.865 D/TESTINFO-001: Table is some_table SQL(schema) is CREATE TABLE some_table (some_column TEXT)
2022-03-05 14:33:17.866 D/TESTINFO: Expected = -1 RetrievedIndex = -1 columns in cursor are:-
2022-03-05 14:33:17.866 D/TESTINFO:     Column Name is some_column

2022-03-05 14:33:17.867 D/TESTINFO-002: Table is some_table SQL(schema) is CREATE TABLE some_table (some_column TEXT, new_column TEXT)
2022-03-05 14:33:17.867 D/TESTINFO: Expected = 1 RetrievedIndex = -1 columns in cursor are:-
2022-03-05 14:33:17.867 D/TESTINFO:     Column Name is some_column

2022-03-05 14:33:17.880 D/TESTINFO: Expected = 1 RetrievedIndex = 1 columns in cursor are:-
2022-03-05 14:33:17.880 D/TESTINFO:     Column Name is some_column
2022-03-05 14:33:17.880 D/TESTINFO:     Column Name is new_column

2022-03-05 14:33:17.889 D/TESTINFO-003: Table is some_table SQL(schema) is CREATE TABLE some_table (some_column TEXT, new_column TEXT)
2022-03-05 14:33:17.889 D/TESTINFO: Expected = 1 RetrievedIndex = 1 columns in cursor are:-
2022-03-05 14:33:17.889 D/TESTINFO:     Column Name is some_column
2022-03-05 14:33:17.889 D/TESTINFO:     Column Name is new_column


2022-03-05 14:33:17.903 D/TESTINFO_JAVA: Expected = 1 Retrieved = -1
2022-03-05 14:33:17.904 D/TESTINFO_JAVA: Expected = 1 Retrieved = -1

Additional

Further testing, using specific column names rather than * (null), seems to indicate buggy code.

Obviously not suitable, as specifying the column if non-existent, would result in an exception.

However, consider, the following

  • as said not really usable but this circumvents the column not found exception to prove the point that null as the 2nd parameter of the query method perhaps doesn't work as intended

    • at a guess extracting the known columns at open and perhaps that the code for WAL handling is a little more solid

:-

class MainActivity : AppCompatActivity() {

    var counter = 0
    override fun onCreate(savedInstanceState: Bundle?) {
        super.onCreate(savedInstanceState)
        setContentView(R.layout.activity_main)

        // Use a fresh DB each time
        val dbPath = this.getDatabasePath(UUID.randomUUID().toString())
        var db = SQLiteDatabase.openDatabase(
            dbPath,
            android.database.sqlite.SQLiteDatabase.OpenParams.Builder()
            //.setJournalMode("TRUNCATE")
            .addOpenFlags(android.database.sqlite.SQLiteDatabase.CREATE_IF_NECESSARY)
            .build()
        )
        //db.enableWriteAheadLogging()

        // Query 1: CREATE TABLE
        db.execSQL("CREATE TABLE some_table (some_column TEXT)")
        showSchemaForTable(db,"some_table","TESTINFO-001")

        // Query 2: SELECT all columns (to assert on index of new_column)
        assertColumnIndex(db, "new_column", -1)

        // Query 3: ALTER TABLE to add column
        db.execSQL("ALTER TABLE some_table ADD new_column TEXT")
        db.execSQL("INSERT OR IGNORE INTO some_table VALUES ('a','b')")
        //showSchemaForTable(db,"some_table","TESTINFO-002")
        assertColumnIndex(db, "new_column", 1)
        //db.close()
        //db = SQLiteDatabase.openDatabase(dbPath.toString(),null,SQLiteDatabase.OPEN_READWRITE)

        // Query 4: SELECT all columns again (to assert on index of new_column)
        assertColumnIndex(db, "new_column", 1)

        // Added to show working equivalent
        db.execSQL("DROP TABLE IF EXISTS some_table")
        db.execSQL("CREATE TABLE IF NOT EXISTS some_table (some_column TEXT, new_column TEXT)")
        //showSchemaForTable(db,"some_table","TESTINFO-003")
        assertColumnIndex(db, "new_column", 1)
    }

    private fun assertColumnIndex(db: SQLiteDatabase, columnName: String, expectedIndex: Int) {
        Log.d("TESTINFO","Invoked assetColumn counter is ${counter}")
        var columns = arrayOf("some_column")
        if (counter > 0) {
            columns = arrayOf("some_column","new_column")
        }
        var cursor = db.query("some_table",  columns, null, null, null, null, null)
        var retrievedIndex = cursor.getColumnIndex(columnName)
        Log.d("TESTINFO", "Expected = ${expectedIndex} RetrievedIndex = ${retrievedIndex} columns in cursor are:-")
        for (cName in cursor.columnNames) {
            Log.d("TESTINFO","\tColumn Name from Cursor is ${cName}")
        }
        counter++
        cursor.close()
    }

    @SuppressLint("Range")
    private fun showSchemaForTable(db: SQLiteDatabase, tableName: String, tag: String) {
        var cursor= db.rawQuery("SELECT * FROM sqlite_master WHERE name = '${tableName}'",null)
        while (cursor.moveToNext()) {
            Log.d(tag,"Table is ${tableName} SQL(schema) is ${cursor.getString(cursor.getColumnIndex("sql"))}")
        }
    }
}

This results in :-

2022-03-16 07:43:14.531 D/TESTINFO-001: Table is some_table SQL(schema) is CREATE TABLE some_table (some_column TEXT)
2022-03-16 07:43:14.531 D/TESTINFO: Invoked assetColumn counter is 0
2022-03-16 07:43:14.531 D/TESTINFO: Expected = -1 RetrievedIndex = -1 columns in cursor are:-
2022-03-16 07:43:14.531 D/TESTINFO:     Column Name from Cursor is some_column

2022-03-16 07:43:14.552 D/TESTINFO: Invoked assetColumn counter is 1
2022-03-16 07:43:14.552 D/TESTINFO: Expected = 1 RetrievedIndex = 1 columns in cursor are:-
2022-03-16 07:43:14.552 D/TESTINFO:     Column Name from Cursor is some_column
2022-03-16 07:43:14.552 D/TESTINFO:     Column Name from Cursor is new_column

2022-03-16 07:43:14.552 D/TESTINFO: Invoked assetColumn counter is 2
2022-03-16 07:43:14.553 D/TESTINFO: Expected = 1 RetrievedIndex = 1 columns in cursor are:-
2022-03-16 07:43:14.553 D/TESTINFO:     Column Name from Cursor is some_column
2022-03-16 07:43:14.553 D/TESTINFO:     Column Name from Cursor is new_column

2022-03-16 07:43:14.577 D/TESTINFO: Invoked assetColumn counter is 3
2022-03-16 07:43:14.578 D/TESTINFO: Expected = 1 RetrievedIndex = 1 columns in cursor are:-
2022-03-16 07:43:14.578 D/TESTINFO:     Column Name from Cursor is some_column
2022-03-16 07:43:14.578 D/TESTINFO:     Column Name from Cursor is new_column
Related