Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Already on GitHub? Sign in to your account

events.js:2549: Uncaught Error: The connection is in an invalid state #52

Open
Vetal981 opened this Issue Aug 2, 2012 · 8 comments

Comments

Projects
None yet
4 participants

Vetal981 commented Aug 2, 2012

I try to use last src from dev benchmark cda03f8 with node v0.6.5 and v0.8.4

I try to write a simple provider of mssql for ueberDB git module.
This error is happend when I start a benchmark that include in ueberDB.
Seems that this benchmark insert asynchronous many records, and after different time I got this error, for example here is log of this benchmark.

d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;24;24;22;23
rows: 200
400;0;82;84;82;23
rows: 400
600;0;67;68;68;24
rows: 600
800;0;84;84;83;24
rows: 800
1000;64;71;71;72;25
rows: 1000
events.js:2549: Uncaught Error: The connection is in an invalid state
events.js:2549: Uncaught Error: The connection is in an invalid state
events.js:2549: Uncaught Error: The connection is in an invalid state
events.js:2549: Uncaught Error: The connection is in an invalid state
^C

d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;37;35;34;23
rows: 200
400;0;85;84;84;23
rows: 400
600;0;73;72;73;24
rows: 600
events.js:2549: Uncaught Error: The connection is in an invalid state
^C

d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;38;35;35;23
rows: 200
400;0;86;85;87;23
rows: 400
600;0;74;75;74;24
rows: 600
events.js:2549: Uncaught Error: The connection is in an invalid state
^C

d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;23;22;22;23
rows: 200
400;0;84;85;84;23
rows: 400
600;0;77;76;76;24
rows: 600
800;1;71;71;71;24
rows: 800
events.js:2549: Uncaught Error: The connection is in an invalid state
events.js:2549: Uncaught Error: The connection is in an invalid state

In one of provider method building very long(seems about 5600 sql commands) sql string which include many delete/insert/select commands in format "select * from aaa; delete from aaa where ...; select * from aaa ; ....." and after this string is executing.
If I try to get from profiler this long generated string and execute without many asynchronous executes all executing fine.

I think you can reproduce it.
You need:

  1. npm install ueberDB
  2. in database create table:
CREATE TABLE [dbo].[test] (
  [Key] varchar(800) NULL,
  [Value] varchar(1200) NULL
)
  1. In ueberDB folder create a new file with name mssql_db.js and put this simple code(need change connection string )
var sql = require('node-sqlserver');
var async = require("async");
var conn_str = "Driver={SQL Server Native Client 11.0};Server={xxx};Database={xxx};Trusted_Connection={Yes};";

exports.database = function(settings)
{
  this.db=null; 
}

exports.database.prototype.init = function(callback)
{
  callback();
}

exports.database.prototype.get = function (key, callback)
{
sql.open(conn_str, function (err, conn) {
    if (err) {
        console.log("Error opening the connection!");
        return;
    }
    conn.queryRaw("select [value] from dbo.test where [key] = '" + key + "'", function (err, results) {
        if (err) {
            console.log("Error running query!");
            return;
        }
        if (results.rows.length > 0)
        {
            callback(null, results.rows[0][0]);
        }
        else
        {
            callback(null, null);
        }
    });
});
}

exports.database.prototype.set = function (key, value, callback)
{

sql.open(conn_str, function (err, conn) {
    if (err) {
        console.log("Error opening the connection!");
        return;
    }
    conn.queryRaw("insert into dbo.test ([key], [value]) values('"+key+"', '"+values+"')", function (err, results) {
        if (err) {
            console.log("Error running query!");
            return;
        }
        callback(null);
    });
});

}

exports.database.prototype.remove = function (key, callback)
{

sql.open(conn_str, function (err, conn) {
    if (err) {
        console.log("Error opening the connection!");
        return;
    }
    conn.queryRaw("delete from dbo.test where [key] = '"+key+"'", function (err, results) {
        if (err) {
            console.log("Error running query!");
            return;
        }
        callback(null);
    });
});

}

exports.database.prototype.doBulk = function (bulk, callback)
{ 

//console.log(bulk);
  var sql_q = "";
  for(var i in bulk)
  {
    if(bulk[i].type == "set")
    {
      sql_q+="INSERT INTO dbo.test ([key], [value]) VALUES (" + escape(bulk[i].key) + ", " + escape(bulk[i].value) + "); ";
    }
    else if(bulk[i].type == "remove")
    {
      sql_q+="delete from dbo.test where [key] = " + escape(bulk[i].key) + "; ";
    }
  }

  var stmt = sql.query(conn_str, sql_q);
  callback(null);

}

exports.database.prototype.close = function(callback)
{
  if(callback) callback();
}

function escape (val) 
{
  var res = val.replace(/'/g, "''");
  res = res.replace(/"/g, "");
  return "'"+res+"'";
};  
  1. run benchmark in ueberDB folder
    node benchmark.js mssql

@wread wread was assigned Aug 2, 2012

Contributor

wread commented Aug 2, 2012

great repro. Thanks! We'll take a look at this.

Contributor

jkint commented Sep 27, 2012

We've made some changes to the error handling and have fixed cases that returned that same error. Could you try with the latest code from the develop branch to see if this still can be reproduced?

Thanks.

Contributor

wread commented Sep 28, 2012

Please try again with latest develop code.

Vetal981 commented Oct 1, 2012

I was try commit 6515954

Error change on

d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;8;7;7;23
rows: 200
400;0;76;73;75;23
rows: 400
600;0;69;69;68;24
rows: 600
JSON-PROBLEM:rtfF7RbNVZ43RqzQZTHavTBZqt3d1xNAu0zA7RuQsABRfSPD5iZFJyW5VTCrAvJH3BG
lu5FONrxvoSsQpRRZTeWK42wtttNtCd0iDezmAfZTohQRb6s7LTw2FUVhZiQSdcFVVR6868sAspHNiI9
oZSIRK1Z2MscT8whDD2oRd8apTlSPcOQvlVLJehwigOII9FQ9m3EBs1FnMI5EkAFEAyPAQULXksG9I5R
oBN4OxSAyXpxTIz2fIe7T3a7ODtQMyrbk5kVfz65MRV5wg8c6bfqqF1MHiA3NIX87hLc1C3CPLX3K2ST
wKuwwkXbJyAp60lP0BWFoxO2ThTfkKtulDOl2uk4Jr9c78MA0kOaLVJQA0RwboFqR6Dx2uTTBzoStGCa
9mLlVisLvRviopaiauZ0kc7KTeobRL4V7zcOi0xSwpr82EUyqG7tMMRIZRWVanNyfNbQtCDn1DxqC1eq
lq5eoVR9Ds20etQK9KO9kSLK3cBvcq58ZPaKBx3N1gTV8Al5iMaiz6kQdkoSvSnJIUxp6bLtBLvSSrFg
zNVqxmMiQ2rOlLazbPTwUOPsfWyzemTsHJ0cJOpGknrmu745yXl28ato9M0RUUsTuuRB3eTyKBMgEdzh
0X84ToxZGlXgo8K2IteXItJTf46Zm6W881rPPHpGHQcqBM4gkZ3xVfR6pBXMrn7MVsSCqgXrZFv6IbMI
dDCGAVpgHvdIoTe8wvP6KOCVqJQGxdzeQTfHANwliAqTTg1aeWcmDT5AQ1BEJPtU93smAFcWJ1Uudkse
UTba1laWetnqX4IEHyx6xopPhhSoZONWTDh9Kp50kTE391euD6cKTp5GIVmQ7RQ0fZZpA6OlnXm6NSKA
6WtsCKZfazXw75syVTmNzPKnoteQOCegxWvL5hviHrmAIUlDKwvQRXJTTwrfmWm0Q9BoM8hVaLam7pTc
fx9CK8RKVn3p0mRzzmlTdEuxDQqW692EcXtn5CPX7romBCfC5v6mC
JSON-PROBLEM:JRBOatKg7lWer5iaaVtUFusVt7RN55zXi25Tkan6UyFOLSihRXKFCaTc6N8OX7BnzxE
wz4f2IUsxgVBbQmMDQtUzSiEfAhwMFrQsCyt89lpes9BSAT2aUt5kclO2vltwhJMKTHEF3DqBoKsfCiQ
vCl9f0DSCrrdOBCc26bMEWryn8TT9dg6KAbWaSNAMGzGGEBKnANPrCmT1XyextMRGxi0XHoKTMOOfWvw
ayutr36Pwv044V4POwwgmC7G0BpuoeOclsaHnpBCTrG5gKn9dRECBLHFXhGDHdkryDRGWJdgkV8ahV1r
UedaDrblNDK7r9oKap4sMdKO76tVyKTdmwCGvZOC0p5Namdzyisb4LBPXO5l00IZV63VETwC4VRNGy5m
ub7DZZw0puBWvPJm3B4TnKwP3kUsTnwaiFS5cJI9D5NgFxcm8fhvnLa2u4xbnHTGzaLPVfLy4yBGeIGw
riHNR4sGidB5D5CXsPLAx69BUL2RBUi9TWe8mcv1xNPwdyfSABhZIL77M0F3D9XCFyJ6A1Ec4fPJCpvT
yrq8goTZ3zKZqWq8a0sJrqV9sKO8KEHotBXBSTrRgcbam926Ook6gtZqe3Mce5WM6G3fP0sMGZ5CtT4q
zvKNhXgtvu5fZ1XKNvquk4il253k3y9X5oGcHoAxTCA8Gqs8Pv2KncukFTAfJbZP2uPJp0lfs91XaH1l
g5hMOnSzP0t4Sv3UdBN4SgLbNvQrdeWB6xo95KMaUsOzU3wPAQ4JuzP6Xs82ST1vRnEF5h2u96F4KL3K
Q7gRiHDn4q1l0hVNOeTkAn4ycNKBXcEUkXBJhSPnI8borL7xccAseGhacxa3sTxDaWQEOPWHXtbbvL2t
dEZc7R9ltJFuMFSoDsSIQ5Qbb6Jf4KbJDzcx3pD0iVO1P13HGbTPymgk0dnoPF3VGqlPMJTaWwRSIbIO
7ZJaqbbmIczHAexvDAQbRcCiQHt6yz71GcHMmLMl780Hx7ox500of
JSON-PROBLEM:NMFh2fWJESaTpOLIqrP1oDzFz1XtUsTJcfvurbhin2vSqWOOqh3OHF0sf3hz4tzK35Q
FXXzh9vwslt32Nl9X3T6zGu5ebbpdi2lg5rUPcQB85CWVPu8J8Ui6NlJxSJJJp3s7MykC4CTTHAJqKTs
gENKx3Fql6sJULslbdLfbv3HJckpfaMvpy5CNkNJ6TmDAJMgXSV1uVmFiviaJtnB1cfNADEIlNgWzF6M
c97vmu1yx12w4zfhSaTKWSAxggMXlztfLNAi8RFw0MUSwrUtdgdElmSHtMREuFlPbDEav6HsxvPT8qec
uQpmLycxePMAfyTytafVbtq4kiR0gg2ZOs72AfT397EK3KcQ4L3Gekg4FRPkShm1IepxidxkcgiZZe4P
CrRM6Vd6mlKD24THq9PGvg3ftOpbmyIbLnZ5rAeJkeGtU6klIhnUpiy9kSwXgvQT5pqhEdM7TAu0ATk3
3q9FadH9KtEXtANDL0q7nukRv24xAzKSpdM34T8ySmZmbsu2tZ6llw8xvwVopZnFW86mpUyzsEROoX06
EMkpE6ZvVPkcPk3S7fnhHsHyhvgIJKp5HWGT3UqhP4NU7lNt20CO3k5d9KMHXDFeWeV53G3qpNOhfveb
tsbsdPoPIiG6VBCZMEdB64DQ1kqJXa5JHyD2FrDya2kbCpGpJO1sSESTegAPuPBJnLKqDK8iFWKiWr1R
p0hOZQi06kT6ECTWLKmVhGqgazroG4e0IUeToN1bQ7JLS1d9rzhfTODhapdizTefNo1eJOdsqboVs6K9
JtowpxELHOF6rXSAhEmNHaqlT4XvuF0ABoLSPxB2A9Zms8QF61lxE0FN3GbfrICwC3oFz4FdSWQO6FO4
JTKsWGEIwTQJBEB05slvD7MU3rnQ0qR9FwC1JPyKteM3689smArVye9s47MgxQgHK8BvSOHNFd2vutM9
AP2XB8LiamZJZbuxXqm9Z3ty7Ch4CumFBAKrkzvolOmoDQ8rgTeSb
SyntaxError: Unexpected token r
    at Object.parse (native)
    at exports.database.get (d:\Services\etherpad-lite-win\node_modules\ueberDB\
CacheAndBufferLayer.js:162:24)
    at exports.database.get (d:\Services\etherpad-lite-win\node_modules\ueberDB\
mssql_db.js:45:4)
    at rowsCompleted (d:\Services\etherpad-lite-win\node_modules\node-sqlserver\
lib\sql.js:220:13)
    at onNextResult (d:\Services\etherpad-lite-win\node_modules\node-sqlserver\l
ib\sql.js:249:13)
finished
time: 0s


d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;38;37;34;23
rows: 200
400;0;89;88;87;23
rows: 400
600;0;62;60;61;24
rows: 600
JSON-PROBLEM:KMTnixk4NlN6cbdx0bc6V8uqeG6O7ky0LpvaRfQ2WJV1OhInkDcQTygFuoIPsaiZ9B1
kTZfiDT73pPRKRhptoEOh6wuGag6oQT1Ku18OHgDmL91wDvxwxFGTdWsQQAKJzztF5MqOlVsx5iOfEZE
nBlACQapsKFruLwZT5JX4bEqT5iORNNhVem7gegTdVBdzSfrqT63Cm8fo5598aJ7uL6bh5Nz9HiSdsKC
QIwcZ36HqDRSgPrghFoWLJLqQKItzZm0NdaTCskc02SewK5Scn1NsyPVFTPfZ7ZR5yuovf0q41GCXmgS
aeT2fmgSD7zHd1vzen5G8Go4FIMLgBVaMN4LU81ETgSTV0BOzEbEPQ0pdEFwoWoJ5oUDruhU4f1Qq2Hb
0Oo1bOBRlHad1AsUmfUvEgOfneFgJrV2NzdHTgLpXeS4nZ2wgsi17fIB0vPA2WZXPvPDg9i5Bi9GiFeD
66T6ftufNIX4CD2kuXkPvZ8ip70iCFb20nMOvXSxQ54etp5OXX5u3xJCwbCuA2rwQ9C3PkowwTTSkTgZ
JSOJAqq8ef72ErQpsztTdAu2S6z4hCCAVuBW4P4akku57d2ksNTpDBr4nHWOgho7UveyvZbWAG4eHCd2
6pnm7eNG2WtM0CbEerPgsxIkU6iAqWTBodKohttXTDTrgIJOWpCNgS8RkcpRlpuJJDsSPLTvTG7uTa5M
WmZn6kaudaZTu1oHOduwaGlUPyEXrpwuD7E19bH3hT7owodiw7VmRQ6bLwwdDkTa7qByg7ymi1z6inv4
ZRmcPbZZG0c1GBRTNTqh02u712VwbstyHdTNbof8bm3Bo415zctA5EoU7J2P7gVqpCLWfeuXfl92WNXk
LeM26FMAAUANZRJK0z2RIUoe16zlosIim1g0hboLpQlNVZg3QvZ3JQ03HxLUViVoZO995V0omFEaPS4M
OgQCs9vCm305tTiLKtahqedzx4HCNKiUOlpmQgnUNzQTxqTQWDwNb
SyntaxError: Unexpected token K
    at Object.parse (native)
    at exports.database.get (d:\Services\etherpad-lite-win\node_modules\ueberDB\
CacheAndBufferLayer.js:162:24)
    at exports.database.get (d:\Services\etherpad-lite-win\node_modules\ueberDB\
mssql_db.js:45:4)
    at rowsCompleted (d:\Services\etherpad-lite-win\node_modules\node-sqlserver\
lib\sql.js:220:13)
    at onNextResult (d:\Services\etherpad-lite-win\node_modules\node-sqlserver\l
ib\sql.js:249:13)
finished
time: 0s


d:\...\node_modules\ueberDB>node benchmark.js mssql
generating random data, to fill database...
done
initalize database...
done
do the first writings to fill the database...
done
values;read_time;write_time;update_time;delete_time;memory_mb
200;0;24;21;22;23
rows: 200
400;0;88;88;88;23
rows: 400
600;0;70;70;70;24
rows: 600
JSON-PROBLEM:qu25WGShBy9ANtnrCJK5Zr85zK2Ta7AtvAIgP20F5aiNwR6JrTJpKGHD42JM3OOUEgP
ota4An1aXbNsZyUlHl6qva52EhCWWCQxT4pTXzcotTbZfXeyZsweSyy19XHu7MDHf2ehlBlLWSGl937m
0i3IWmZtmGoubdEJakcfDHua3FxTBo1E0FTdv8Gv2wT3mgbFBLTgbzmu6ps2XLcGTrsHtLe8qN2QWCuA
ukBWP8BzfnpOq8iZhyVbtHI8mO0pxC31TS74NbiToBnpNci40fipTrmbTf2Gws6KWvQQ82bwLwqhbfXo
pDa0KSlpWMyFUuRaZdCBw0oytcWpy5VrIstOOTt9pLhSBxLSI678DGZDwOSGcCl9C6cXLIzbN7Jke8oR
wJkJnIZbE3e2pTDrhh0V6IvCXhE5TSBxzlxRsWIv549TxfWQPP8GWcxagTFFemgQfLTe3HHtDitFAURn
OiZTn7Kd3f77rMRJR4t6mTe6xXCoC36DIl0OUOoL0OZ00LowpOhyBoP8xNAEpiHLB9hppsTIcovLtqtM
LIbIPkxgKATJFWQzetBTMouFmQIWu6oKXRqGdMvCIQUbc6OUsi7aF4GQWHwRimp0Xamw7VpR42QzvZUO
SLEpvoaPJAXvy9BMUqFZberc6AWZK2JgsCrhfCT8IOD3uri55HQwDfACzQBChIExz0pautTsh4qFd3DH
b76JnnC3enCMXG36JaNFrpd1mBuCED2NwSurcT6Q01PTB5T6rbCgiPVuoJQTWxTlIeNyMafLAllSOD9m
uAnIS7Ekqn5CbpwAgEnViZ2neCilv06nUobMPVuIo3A3eywQOTTFuO6FHI8S5zsfdIofWRQFMn7O0xPZ
27IH35Pu1ITqUWyRiDrhVAUswECywc2yRzsZtHAqtaknVWED5BFPVbgaTxdoQMMM5siz9bpqeTqR6zLT
tcB0eCSKh0yzEWtfBwWnmaWWQZFD5uxSg3qW4WRIbfZc89D0OTDa9
JSON-PROBLEM:7H0S05M6e3ytL0TPiZqG4rO0FSNpwQNvQdvQVpW44TFRZIkSPG6uOBgVeAuwTrCQAlt
e3x1e7zOm0Qqfpbx9UAhN2yDrV3guwtrXai7MVCdQrcidndUsZVBxEW8cepDTzN9K7lnW2eIBOWLHNTh
uHrGQFZShLbQCboayqhZGteK10z7xTr7KnXG2Fc27pSIaWwMQEyKhnc67ogtMkwRQD9Z9i0kfhTwh0Bm
bTkVXZp6M9k9wwxE5G7PEQD6xrLkzlvBI9MGed1aQbBrJVnryULmJM0taGJLUGH3wJiwa4W3VBPrr55L
iGvkZ58mMnUaNRCCaqKU4JCI22vObposPSFUuCaxzXPUe5ooX6NRV37kqqiPNVZ67BKuPkJAX4nVKw57
49fNLDxuvxlGpcVkMU04yp1S22Ivs1QUD4Iz35RGDIZ6kk8llkeF7bygzqFTTGvCLkvEybvkRhKqwoPR
zE4TGmihykdfDcNzsiZ3ulZRzcLbqr9v8UCBzbATJAr1ZNpGR0bJskSdqOGLxkTlOZvRUfDXQAswdZ1z
7UCfz5PG5kMNTABXloeMqyhPfdBhaQ98E8zotN9Mq141FFbgAu5By8NSd0TLgUEbLhreZwlhdI2fxBh3
SCHFNB134Gq8VpsnzuPvsCAGW2oWf7Pt7BLNQLh7DkhpgF9fTCF3OAs5WzkxTfF3klTowPh7JHtpCqZL
4xsuScbNsQENrDsEDTLpVMaBefzTN31iJ1XwdkCqkzAQna90TaLqy28ULVXRBIEoxOpruxEBWXTHmvG3
TC6Wy4a0cRqpLu57ZKVWHE5u6oGd8FkB8uwteB8T5yDP1y5UvMmbPmThAv9IbnW6XwnP6HHgW2rh5cwe
JIUWKLmHig3dTpzJAUhrIBzzb5xT7BOqP1gg7pQOrNgFUz3ervHuJhu7ln5UKTDd7xs3HJgPaU0B3wC3
UV3B9zmb60N0bA23qi0afOSP2c4peRTwWqmEolfWHguXg9fVZSgyx
SyntaxError: Unexpected token q
    at Object.parse (native)
    at exports.database.get (d:\Services\etherpad-lite-win\node_modules\ueberDB\
CacheAndBufferLayer.js:162:24)
    at exports.database.get (d:\Services\etherpad-lite-win\node_modules\ueberDB\
mssql_db.js:45:4)
    at rowsCompleted (d:\Services\etherpad-lite-win\node_modules\node-sqlserver\
lib\sql.js:220:13)
    at onNextResult (d:\Services\etherpad-lite-win\node_modules\node-sqlserver\l
ib\sql.js:249:13)
finished
time: 0s

d:\Services\etherpad-lite-win\node_modules\ueberDB>

So, seems now exception in ueberDB?

That would be my first guess, though without looking at it in detail I couldn't say for certain.

Since ueberdb is licensed with the Apache 2.0 license, there is a good chance I can get approval to look at it directly (IP concerns and what not). Otherwise, I'll have to rely on your expertise to help me debug this if it's in our driver.

If you have a smaller code snippet that reproduces the problem, that would be ideal.

Vetal981 commented Oct 1, 2012

icosahedron
I just run again 4 steps that I described in my first post)

Vetal981 commented Oct 3, 2012

icosahedron
So, can you reproduce this bug?

Contributor

jkint commented Oct 3, 2012

I have not yet tried. Other matters have kept me busy. I hope to get to it later this week.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment