Node-oracledb: segmentation fault when querying clobs using promises/async

[jarlestabell]

I just tried making some async code using node-oracledb version 1.12 and TypeScript. I'm playing around to learn the abstractions, so it's not meant to be efficient or anything! (I noticed the current TS-type wrapper is missing the getRows function)

Here's a simple class having two member functions:

export class ConnectionWrapper {
    constructor(private readonly connection: oracledb.IConnection) {
    }
    executeAsResultSet = async (sql: string, bindParams: any[], asObjects: boolean):     Promise<oracledb.IResultSet> => {
        const options = {
           resultSet: true, outFormat: asObjects ? oracledb.OBJECT : oracledb.ARRAY,

        };
        const maybeResultSet = (await this.connection.execute(sql, bindParams, options)).resultSet
        if (maybeResultSet) {
            return maybeResultSet
        }
        else
            throw Error('Unable to get resultset from query');
    }

    executeForEachObject = async <T>(sql: string, params: any[], handler: (T) => void) => {
        const resultSet = await this.executeAsResultSet(sql, params, true);
        try {
            let row = (await resultSet.getRow()) as T;
            console.log(`row: ${JSON.stringify(row)}`);
            while (row) {
                handler(row);
                console.log(`fetchAsString: ${JSON.stringify(oracledb.fetchAsString)}`);
                row = (await resultSet.getRow()) as T;
                console.log(`row: ${JSON.stringify(row)}`);
            }

        } finally {
            resultSet.close();
        }
    }
}

The logging is only frantic attempts at debuggig! :)
(oracledb.fetchAsString is [2006], as expected. )

Here is how I call it:

   const svar = await myConn.executeForEachObject<model.Gjenstand>(`select ART_ID, MUSEUMSNR, RAPPORT from usd_ark_gjenstand_ntnu.gjenstand t where t.art_id < 140`, [], 
        gj=> console.log(`art_id: ${gj.ART_ID} museumsnr: ${gj.MUSEUMSNR}`)
   );

Rapport is a CLOB. It is empty in all rows returned for the query.
I consistently get a segfault, but it varies how many rows it fetches before I get the segfault.
I don't get this segfault if I remove the Rapport field.
I get the segfault irrespective of whether I set:
(oracledb as any).fetchAsString = [ oracledb.CLOB ];
or not.

Here's a crash log:
PID 363 received SIGSEGV for address: 0x91
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/segfault-handler/build/Release/segfault-ha
ndler.node(+0x1b98)[0x7f8db8d5eb98]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f8dd71d5390]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZN10
Connection11cbDynDefineEPvmjPmPS0_PPjS2_PPt+0x36)[0x7f8dd4bc7dd6]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZN8S
tmtImpl14defineCallbackEPvP9OCIDefinejPS0_PPjPhS3_PPt+0x2d)[0x7f8dd4be949d]
/opt/oracle/instantclient/libclntsh.so.12.1(kpufGetRcvInfo+0x2ad)[0x7f8dc55ccc5d]
/opt/oracle/instantclient/libclntsh.so.12.1(ttccpwg+0x1e9)[0x7f8dc68fd6e9]
/opt/oracle/instantclient/libclntsh.so.12.1(ttcfour+0x35a)[0x7f8dc738e60a]
/opt/oracle/instantclient/libclntsh.so.12.1(ttcdrv+0x4184)[0x7f8dc73861c4]
/opt/oracle/instantclient/libclntsh.so.12.1(nioqwa+0x49)[0x7f8dc73714c9]
/opt/oracle/instantclient/libclntsh.so.12.1(upirtrc+0x55c)[0x7f8dc73535cc]
/opt/oracle/instantclient/libclntsh.so.12.1(kpurcsc+0x66)[0x7f8dc735dde6]
/opt/oracle/instantclient/libclntsh.so.12.1(kpufch0+0x715)[0x7f8dc735b445]
/opt/oracle/instantclient/libclntsh.so.12.1(kpufch+0x575)[0x7f8dc7359aa5]
/opt/oracle/instantclient/libclntsh.so.12.1(OCIStmtFetch2+0xb)[0x7f8dc5570ffb]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZN8S
tmtImpl5fetchEj+0x26)[0x7f8dd4be9b86]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZN10
Connection7DoFetchEP6eBaton+0x30)[0x7f8dd4bcdc10]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZN9R
esultSet13Async_GetRowsEP9uv_work_s+0x324)[0x7f8dd4bdeae4]
node[0x122aa41]
node[0x1239b79]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f8dd71cb6ba]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f8dd6f0182d]
[1] 363 abort (core dumped) node dist/index.js

There doesn't seem to be a problem if I use plain old callbacks to do the same query, it's only the promise/async which crashes.

[cjbj]

Can you see if there is something about the actual data? Can you give the table schema? Can you try and create a standalone file that reproduces the behavior? Can you give the versions of the the oracle client and DB? And confirm whether you are using 1.12 or 12.2 of node-oracledb?

[dossy]

I'm new to node-oracledb but not new to Oracle, and running into a similar segfault issue when executing SELECT queries including CLOB columns. Using [email protected] and [email protected] here, on Amazon Linux 2016.09 using Oracle InstantClient 11.2.0.4.0, connecting to Oracle 11g 11.2.0.4.0, using node v6.9.5.

Here's the gdb backtrace of the segfault:

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffe5274700 (LWP 13011)]
0x00007ffff6c095f7 in raise () from /lib64/libc.so.6
(gdb) bt
#0  0x00007ffff6c095f7 in raise () from /lib64/libc.so.6
#1  0x00007ffff6c0ace8 in abort () from /lib64/libc.so.6
#2  0x00007ffff6c49327 in __libc_message () from /lib64/libc.so.6
#3  0x00007ffff6c4f194 in malloc_printerr () from /lib64/libc.so.6
#4  0x00007ffff6c54a79 in realloc () from /lib64/libc.so.6
#5  0x00007ffff499c281 in Connection::cbDynDefine(void*, unsigned long, unsigned int, unsigned long*, void**, unsigned int**, void**, unsigned short**) ()
   from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#6  0x00007ffff49c17c8 in StmtImpl::defineCallback(void*, OCIDefine*, unsigned int, void**, unsigned int**, unsigned char*, void**, unsigned short**) ()
   from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#7  0x00007fffe5bb663a in kpufGetRcvInfo () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#8  0x00007fffe6e80eda in ttccpwg () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#9  0x00007fffe77a82d4 in ttcfour () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#10 0x00007fffe779f2cb in ttcdrv () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#11 0x00007fffe774c251 in nioqwa () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#12 0x00007fffe77365ce in upirtrc () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#13 0x00007fffe773c2be in kpurcsc () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#14 0x00007fffe5bb3811 in kpufch0 () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#15 0x00007fffe5bb1d4f in kpufch () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#16 0x00007fffe5b46c4b in OCIStmtFetch2 () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#17 0x00007ffff49c1e36 in StmtImpl::fetch(unsigned int) () from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#18 0x00007ffff49a49a1 in Connection::DoFetch(eBaton*) () from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#19 0x00007ffff49b64e4 in ResultSet::Async_GetRows(uv_work_s*) () from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#20 0x000000000121f021 in worker ()
#21 0x000000000122cf49 in uv__thread_start ()
#22 0x00007ffff6f9ddc5 in start_thread () from /lib64/libpthread.so.0
#23 0x00007ffff6ccac9d in clone () from /lib64/libc.so.6

I'll work on creating a minimal reproducible test case, if there are others who can look into this...

[dossy]

Okay, here it is:

create table issue_609 (id number, data clob);

insert into issue_609 values (1, 'foo');
insert into issue_609 values (2, 'bar');
insert into issue_609 values (3, 'baz');

SQL> select * from issue_609;

        ID DATA
---------- ------------------------------------------------------------
         1 foo
         2 bar
         3 baz

Then, my issue_609.js test:

var db = require('oracledb');
db.fetchAsString = [ db.CLOB ];
db.maxRows = 1;

db.getConnection({
  user: 'USERNAME', password: 'PASSWORD', connectString: '//HOST/SID'
}, function (err, conn) {
  var stream = conn.queryStream('SELECT * FROM issue_609', [], {});

  stream.on('error', console.error);
  stream.on('end', conn.close);
  stream.on('data', console.log);
});

And, running it under gdb:

(gdb) run
Starting program: /usr/bin/node issue_609.js
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
[New Thread 0x7ffff7ff6700 (LWP 13834)]
[New Thread 0x7ffff6bd3700 (LWP 13835)]
[New Thread 0x7ffff63d2700 (LWP 13836)]
[New Thread 0x7ffff5bd1700 (LWP 13837)]
[New Thread 0x7ffff53d0700 (LWP 13838)]
[New Thread 0x7fffe5274700 (LWP 13839)]
[New Thread 0x7fffe4a73700 (LWP 13840)]
[New Thread 0x7fffd8dc4700 (LWP 13841)]
[New Thread 0x7fffd85c3700 (LWP 13842)]
[ 1, 'foo' ]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffd8dc4700 (LWP 13841)]
0x00007ffff499c23d in Connection::cbDynDefine(void*, unsigned long, unsigned int, unsigned long*, void**, unsigned int**, void**, unsigned short**) ()
   from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
(gdb) bt
#0  0x00007ffff499c23d in Connection::cbDynDefine(void*, unsigned long, unsigned int, unsigned long*, void**, unsigned int**, void**, unsigned short**) ()
   from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#1  0x00007ffff49c17c8 in StmtImpl::defineCallback(void*, OCIDefine*, unsigned int, void**, unsigned int**, unsigned char*, void**, unsigned short**) ()
   from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#2  0x00007fffe5bb663a in kpufGetRcvInfo () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#3  0x00007fffe6e80eda in ttccpwg () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#4  0x00007fffe77a82d4 in ttcfour () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#5  0x00007fffe779f2cb in ttcdrv () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#6  0x00007fffe774c251 in nioqwa () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#7  0x00007fffe77365ce in upirtrc () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#8  0x00007fffe773c2be in kpurcsc () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#9  0x00007fffe5bb3811 in kpufch0 () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#10 0x00007fffe5bb1d4f in kpufch () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#11 0x00007fffe5b46c4b in OCIStmtFetch2 () from /usr/lib/oracle/11.2/client64/lib/libclntsh.so.11.1
#12 0x00007ffff49c1e36 in StmtImpl::fetch(unsigned int) () from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#13 0x00007ffff49a49a1 in Connection::DoFetch(eBaton*) () from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#14 0x00007ffff49b64e4 in ResultSet::Async_GetRows(uv_work_s*) () from /var/lib/pgsql95/ora2pg-transport/node_modules/oracledb/build/Release/oracledb.node
#15 0x000000000121f021 in worker ()
#16 0x000000000122cf49 in uv__thread_start ()
#17 0x00007ffff6f9ddc5 in start_thread () from /lib64/libpthread.so.0
#18 0x00007ffff6ccac9d in clone () from /lib64/libc.so.6

This is reliably reproducible, every time. Basically, when you exceed maxRows, it segfaults. My guess is some pointer is getting clobbered ... I'll start taking a look at the oracledb source, now, but hopefully this will get some more eyeballs on the problem quicker!

[jarlestabell]

I guess my problem is essentially the same.
I'm using oracledb vs 1.12.2
instant client: Client Shared Library 64-bit - 12.1.0.2.0
node: 6.4.0
My local OS: Ubuntu 16.04
Oracle DB: Enterprise Edition Release 12.1.0.2.0 (On another Linux server, accessed via a SSH tunnel)
NLS_CHARACTERSET: AL32UTF8

I attach a project sample.
I don't touch maxRows, but then I need more than a couple of rows to get the problem. I inserted 40 rows into a dummy table with this structure:
CREATE TABLE TABLE1 (
COL1 CLOB,
ID NUMBER(22,0)
) ;

NOTE: When I remove
(oracledb as any).fetchAsString = [oracledb.CLOB];
the problem disappears in my case (I haven't tested dossy's case)!

node-oracledb-problem2.zip

Once I got a totally different segfault:

* Error in `node': malloc(): smallbin double linked list corrupted: 0x00007fa6c803cb60 *
======= Backtrace: =========
/lib/x86_64-linux-gnu/libc.so.6(+0x777e5)[0x7fa6eeae67e5]
/lib/x86_64-linux-gnu/libc.so.6(+0x81d61)[0x7fa6eeaf0d61]
/lib/x86_64-linux-gnu/libc.so.6(__libc_malloc+0x54)[0x7fa6eeaf25d4]
/usr/lib/x86_64-linux-gnu/libstdc++.so.6(_Znwm+0x18)[0x7fa6ef601e78]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZNSt
6vectorIP9ExtDefineSaIS1_EE14_M_fill_insertEN9__gnu_cxx17__normal_iteratorIPS1_S3_EEmRKS1_+0x405)[0x7fa6ec84c965]
/home/jarle/src/dsmusit/data-transformation/2017/ntnu-vm-gjenstandstype-normering/node_modules/oracledb/build/Release/oracledb.node(_ZN9R
esultSet13Async_GetRowsEP9uv_work_s+0x387)[0x7fa6ec852b47]
node[0x122aa41]
node[0x1239b79]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7fa6eee3f6ba]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fa6eeb7582d]
======= Memory map: ========
00400000-01ab6000 r-xp 00000000 08:07 6947597 /home/jarle/.nvm/versions/node/v6.4.0/bin/node
01cb5000-01ccf000 rw-p 016b5000 08:07 6947597 /home/jarle/.nvm/versions/node/v6.4.0/bin/node
01ccf000-01ce2000 rw-p 00000000 00:00 0
....

[cjbj]

@dossy thanks for the very concise testcase. We'll look into it. Seems to be a dup of something our testing group recently reported. Is bumping maxRows a workaround for you - or do you not know how many records are coming back? FWIW @anthony-tuininga was playing with the testcase and indicated the not-yet-out node-oracledb v2 branch doesn't suffer the problem.

@jarlestabell Can you try bumping maxRows too? Got a standalone testcase?

[edited to fix tags]

[dossy]

@cjbj I'm working on a bulk export/import tool, so the number of rows will exceed available RAM, so I can't set maxRows that large.

Glad to hear that v2 may have fixed this problem, but it's probably important to get this fixed in v1 unless v2 is imminent and people are likely to upgrade quickly?

[cjbj]

@dossy Does it ever reproduce if maxRows is 100+? @anthony-tuininga (who is out today) seemed to think this was a solution but I wasn't sure if he meant in his quick test, or generally.

And yes, a v1 fix would be nice.

[dossy]

@cjbj Let's see:

create table issue_609 (id number, data clob);
begin for i in 1..200 loop insert into issue_609 (id, data) values (i, i); end loop; end;

Running the same issue_609.js I provided earlier except removing the db.maxRows = 1; line, I get:

$ node issue_609.js
[ 1, '1' ]
[ 2, '2' ]
... output elided for brevity ...
[ 98, '98' ]
[ 99, '99' ]
[ 100, '100' ]
Segmentation fault

If I set db.maxRows to a value greater than or equal to 200 (the number of rows in the table, all of which are returned by the SELECT query with no WHERE clause), it runs fine. If I set it to 199 or less, it segfaults.

Also, my issue_609.js needs a small tweak for correctness's sake, modifying this line:

  stream.on('end', conn.close);

to be:

  stream.on('end', conn.close.bind(conn));

[cjbj]

@dossy thanks for testing. We'll take a look.

[cjbj]

@jarlestabell @dossy can you test with 1.13?

[jarlestabell]

1.13 fixed the problem for me, great, thanks! :)