error caused by ABORT renders db unresponsive forever

[dronus]

Encountered with node.js v0.10.25:

If a column has an UNIQUE constraint with the ON CONFLICT ABORT rule, an attempt to insert a non-unique value is correctly answered by an error:

"Error: near line 1: column email is not unique"

However, db is fucked up afterwards, and no callbacks will ever be called by db.query again, tearing down all db-dependent querys to node.js. I will investigate this further.

[dronus]

The error message in this case also is leaky: If no handler is attached to the UNIQUE-violating INSERT query, the error fires up on some other query, eg. SELECT, which of course can not return this error by itself.

[WebReflection]

this looks pretty bad … in order to help ASAP I wonder if you could:

• tell me which version of dblite you are using
• give me a basic table schema to test against in order to verify the problem through a query that you know will repeat the issue
• tell me if you had this problem before or with other version of node

Thanks a lot!

[dronus]

Using SQLite version 3.7.9 .

[dronus]

This is a timing issue it seams: The 'INSERT INTO' db.query call invokes the callback before the query has failed. If the callback just prints 'err' to the console, one can see 'err' is null, while another error message pops up on the console shortly after, if not captured by an subsequent abitrary db.query fast enough it seems. Found that with more simple test code.

However, under certain conditions not really clear to me (production code), the callback actually gets the error message right, but then db.query would not call an callback anymore forever.

[dronus]

Clearly a synchronisation issue, subsequent runs of the same code in a fresh node showing different outcomes, sometimes capturing the err, sometimes not.

[dronus]

simple example that produces different, buggy outputs on repeated runs:

test.sqlite dump:

CREATE TABLE users (id INTEGER PRIMARY KEY ON CONFLICT REPLACE, email TEXT UNIQUE ON CONFLICT ABORT);
INSERT INTO "users" VALUES(1,'foo@example.com');
INSERT INTO "users" VALUES(2,'bar@example.com');

test.js:

var dblite  = require('dblite' );

var db=dblite('test.sqlite');

db.query('INSERT INTO users (id,email) VALUES(?,?)',['1','bar@example.com'],function(err,data){
    console.log('E:'+err+' D:'+data);
});

db.query('SELECT * FROM users WHERE id=1',function(err,data){
    console.log('E:'+err+' D:'+data);
});

[dronus]

As my sqlite3 was quite old, I managed to install 3.8.3.1. The error message changed, the erratic behaviour persists. OS is Ubuntu 12.04 x64.

[WebReflection]

I've quickly done some test and it looks to me the callback is consistently fired as expected when the error occur, and such error is reported.

I hav updated the test file and when an error occur it is passed through the callback indeed.

I wonder if you are expecting queries to keep running even if there are errors in the database 'cause it looks to me that if you don't care about errors you should not create tables able to abort or you should use transactions.

A way to solve your issue with such structure would be:

db.query(
  'INSERT INTO users (id,email) VALUES(?,?)', 
  [1, 'bar@example.com'],
  function(err,data){
    if (err) {
      return console.error(err);
    }
    db.query('SELECT * FROM users WHERE id=1',function(err,data){
      console.log(data);
    });
  }
);

Or you could use a queue system and when errors occur you decide what to do with a .next() call in such queue.

Does this answer/help?

[WebReflection]

another example would be:

db
  .on('error', function(err) {
    console.log('something terrible happened, rebooting', err);
    process.exit();
  })
  .query('INSERT INTO users (id,email) VALUES(?,?)', [1, 'bar@example.com']);
  .query('SELECT * FROM users WHERE id=?', [1], function(err, data){
    console.log(data);
  });

in this case you can care about errors in a single point, the on("error") callback … long story short: you need to nest callbacks if there is a risk of a failure from the DB or you have a database in an inconsistent state with possibly corrupted data.

I'd rather prefer a silent pause than a eerie of queries that keeps running believing everything happened before was OK, you know what I mean?

Please do not hesitate to ask me more, if necessary. Thanks

[WebReflection]

FYI .. it looks like Travis CI is having similar issue with node 0.8, but green lights on node 0.10

[dronus]

I don't think the problem should be intercepted by error handlers, as it is not caused by sqlite3 errors itself, nor the content or errors of the database. It triggers even with my small example database stated above, which is NOT modified in the test case, so keeps the same every try. The problem however, is triggered again and again, if the test case script is invoked repeatedly.

If the problem occurs, the complete output of my test code is:

> node test.js
E:Error: Error: near line 1: UNIQUE constraint failed: users.email
 D:null

where we completely miss the SELECT query output, because db.query is frozen like I first reported. It can never be used again, no callback will be called.

But sometimes I encounter:

> node test.js
E:null D:undefined
E:Error: Error: near line 1: UNIQUE constraint failed: users.email D:null

Here we see the INSERT query complete, but don't report the ABORT error. The error is then caught by the finished SELECT query, rendering data to null and reporting the error in the wrong place. db.query is not frozen and will do further queries in this case.

Question is if you can reproduce this behaviour, and if not, if this is tied to the used OS / libc or whatever?

[dronus]

a small thought: If we talk about the query callback err, we do not talk about an error in sense of some code problem, but about a condition that can be used for reporting ON CONFLICT constraint clauses like ABORT. It just may indicate some legit condition, such as something is already there and do not need to be stored again.

[dronus]

This is a hard one! Actually, your new test works fine for me.
However, the following self-contained code does not:

var dblite  = require('dblite' );

var db=dblite('/tmp/test.sqlite');

db
    .query('DROP TABLE users;')
    .query('CREATE TABLE users (id INTEGER PRIMARY KEY ON CONFLICT REPLACE, email TEXT UNIQUE ON CONFLICT ABORT)')
    .query('INSERT INTO users VALUES(?, ?)', [1, 'foo@example.com'])
    .query('INSERT INTO users VALUES(?, ?)', [2, 'bar@example.com'])
    .query('INSERT INTO users VALUES(?,?)',[1,'bar@example.com'],
        function(err,data){
            console.log('E:'+err+' D:'+data);
        }
    )
    .query('SELECT * FROM users WHERE id=?',[1],
        function(err,data){
            console.log('E:'+err+' D:'+data);
        }
    );

I would expect two console outputs like 'E: .. D: ..' from it. However, only one is returned on all machines I tested on. Can you please try this too?

[dronus]

The problem was introduced by commit 939ec0c . Prior version is working as expected!

[dronus]

What may going on: stderr and stdout of the sqlite process are not synchronized by any mechanism. If sqlite purges both pipes without much delay inbetween, it is upon kernel buffering and scheduling which fd blocking will release first, and thus you cannot rely on the exact relative order of stdout and stderr output.

If two queries are issued at once, the stdout and stderr callbacks may fire intertweened for the both queries. Query 1's stderr may be delayed after Query 1's stdout. Thus query one would miss the error message, and query two would receive wasError, discarding it's output and killing it's callback. For query two we now would neither fire an error nor data callback.