Skip to content
New issue

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

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Cannot read property 'handleRowDescription' of null #2556

Closed
SergeiLL opened this issue May 29, 2021 · 15 comments · Fixed by #2753
Closed

Cannot read property 'handleRowDescription' of null #2556

SergeiLL opened this issue May 29, 2021 · 15 comments · Fixed by #2753
Labels
waiting for more info

Comments

@SergeiLL
Copy link

Hi.
We have updated our set up from

nodejs 14.4.0
Ubuntu 18.04.4 LTS
psql (PostgreSQL) 12.1
pg 8.2.1

to:

nodejs 16.1.0
Ubuntu 20.04.2 LTS
psql (PostgreSQL) 12.6
pg 8.6

After that, the pg connection started crashing.
Before the update, our code had been working properly for several years.
The error is floating. The error can appear several times a day, or maybe after a few days (7-8).

2021-05-29T09:42:16.192Z TypeError: Cannot read property 'handleRowDescription' of null
at Client._handleRowDescription (/home/user_name/node_modules/pg/lib/client.js:340:22)
at Connection.emit (node:events:365:28)
at Connection.emit (node:domain:470:12)
at /home/user_name/node_modules/pg/lib/connection.js:114:12
at Parser.parse (/home/user_name/node_modules/pg-protocol/dist/parser.js:40:17)
at Socket. (/home/user_name/node_modules/pg-protocol/dist/index.js:11:42)
at Socket.emit (node:events:365:28)
at Socket.emit (node:domain:470:12)
at addChunk (node:internal/streams/readable:314:12)
at readableAddChunk (node:internal/streams/readable:289:9) TypeError: Cannot read property 'handleRowDescription' of null
at Client._handleRowDescription (/home/user_name/node_modules/pg/lib/client.js:340:22)
at Connection.emit (node:events:365:28)
at Connection.emit (node:domain:470:12)
at /home/user_name/node_modules/pg/lib/connection.js:114:12
at Parser.parse (/home/user_name/node_modules/pg-protocol/dist/parser.js:40:17)
at Socket. (/home/user_name/node_modules/pg-protocol/dist/index.js:11:42)
at Socket.emit (node:events:365:28)
at Socket.emit (node:domain:470:12)
at addChunk (node:internal/streams/readable:314:12)
at readableAddChunk (node:internal/streams/readable:289:9)

Any advice?
@brianc
Copy link
Owner

brianc commented May 29, 2021 via email

@charmander
Copy link
Collaborator

Also, are you able to revert just the version of pg for a while? It’d be nice to rule out all the other upgrades if possible. :)

@SergeiLL
Copy link
Author

Hi.
I downgraded PG to 8.2.1. the bug was repeated.
Unfortunately, I cannot show the code. The project is commercial.

@brianc
Copy link
Owner

brianc commented Jun 15, 2021 via email

@repl-chris
Copy link

@SergeiLL did you ever figure this one out?....we are seeing the same thing....

@SergeiLL
Copy link
Author

SergeiLL commented Sep 6, 2021

@repl-chris
We started using pg-native. This problem has disappeared.
But a new one appeared - a memory leak.
The heap size is stable. At the same time, RSS memory grows.
We are forced to restart our scripts. But it's better than having uncontrolled crashes. Although still bad due to memory leaks.

@liam-lai
Copy link

Same issue after upgrade from node8, pg 7.4.1 to node 14, pg 8.6

@charmander
Copy link
Collaborator

@liam-lai Do you have code/setup details to reproduce the issue?

@liam-lai
Copy link

liam-lai commented Sep 21, 2021 •
edited
Loading

@charmander nah, unfortunately. I am now trying to monitor, it happens intermediately. Will share if I get more details

Update: Looks like its my data issue, there is something like Cannot read property 'name' of undefined error msg before handleRowDescription msg

@repl-chris
Copy link

FYI we found the cause of ours - using pg-query-stream, we were sometimes releasing the client before the stream had been read all the way to the end....when this happens the client is returned to the pool and it eventually throws that error and crashes the process. We made the change to call client.release(!didReadAllTheWayToTheEndOfTheStream) in that situation and we haven't seen the error since.

@dhenson02
Copy link

dhenson02 commented Jan 14, 2022 •
edited
Loading

Same issue after upgrade from 7.18.2 to 8.2.1 (which we only did because using 7.18.2 on Node 14 was thoroughly broken)

Windows Server 2019
Node: 14.17.6
node-postgres: 8.2.1
PostgreSQL: 13

I tried to reproduce artificially by running the code below (and other variations of it - swapping order of SLOW, IMMEDIATE and ERROR queries with each other) and hitting with curl directly, but no luck :(

app.get('/abc', ( req, res ) => {
    for ( let i = 0; i < 5000; i++ ) {
        if ( i % 40 === 0 ) {
            // SLOW
            // Millions of rows, no indexes
            helper.query(`SELECT * FROM zip_codes where city_name ilike 'a%'`, ( error, response ) => {
                logger.logInfo(`${i} ${response.rowCount}`);
            });
        }
        
        // IMMEDIATE
        // with an occasional empty result
        helper.query(`SELECT now(), $1, $2::INT WHERE $2::INT % 1000 != 0`, [ { abc: true }, ~~i ], ( error, response ) => {
            logger.logInfo(`${i} ${response.rowCount}`);
            if ( response.rowCount === 0 ) logger.logError(new Error('generic error text'));
        });
        
        if ( i % 400 === 0 ) {
            // IMMEDIATE + ERROR
            // quick fail with params
            helper.query(`SELECT now(), $1, $2, AND AND`, [ { abc: true }, i ], ( error, response ) => {
                logger.logInfo(`${i} ${response.rowCount}`);
            });
        }
    }
});

All the functions in here do what you would expect

  • helper.query(...) calls what results from the connected client's .query()
  • logger.logInfo/logError hook into pino and log input args
  • app.get(...) is from express

PS - it's worth noting this and #1105 occur occasionally together (but not always). Either way has the same root cause of a null client.activeQuery that never recovers. Also this appears to be a duplicate of #1674

@prust
Copy link
Contributor

prust commented May 13, 2022 •
edited
Loading

@charmander: I got a consistent repro of this bug in our tests (on [email protected]) and was able to reduce the code down to this:

let pg = require('pg');

// FWIW `new pg.Client(process.env.DATABASE_URL)` and `.connect()` will also repro the bug
var pool = new pg.Pool({
  connectionString: process.env.DATABASE_URL,
  idleTimeoutMillis: 0
});

// this can be pretty much any query
let sql = `SELECT * FROM pg_catalog.pg_tables WHERE schemaname = 'public'`;

pool.query(sql, [], function() {
  // throw an error in the callback of the first query
  throw new Error('test');
});

setTimeout(function() {
  // the next query will fail with `Cannot read property 'handleRowDescription' of null`
  // because `this.activeQuery` is null
  pool.query(sql);
}, 500);

// an uncaughtException handler (which mocha & other assert-driven test frameworks use)
// is necessary so the process doesn't exit after the first error
process.on('uncaughtException', err => {
  console.error(`Uncaught Error: ${err.message}`);
});

Note that I also got the #1105 error once, but every other time I got Cannot read property 'handleRowDescription' of null.

@charmander
Copy link
Collaborator

@prust Thanks for putting that together. Resuming after uncaughtException isn’t normal, but pg can probably do something to clean up after uncaught exceptions in callbacks anyway. (Or get rid of callbacks and require promises in a future version?)

@dhenson02
Copy link

I forgot to mention I ended up narrowing down to the same reproduction @prust shows here and solved it (at least locally in my own project) by wrapping the callback in a try-catch before moving on

function runQuery ( sql, values, _cb ) {
    function cb ( ...args ) {
        try {
            return _cb(...args);
        }
        catch (e) {
            console.error(e);
        }
    }

    return pool.query(sql, values, cb);
}

^ for those needing a quicker workaround

@prust
Copy link
Contributor

prust commented May 13, 2022

@dhenson02: Thanks! One downside of this workaround is that it has the side effect of making errors less visible (though they are still be emitted to stderr). This is particularly bad in the context of a test suite, where you want errors to be detected and reported by the test framework (mocha, jest, etc).

Your workaround can be modified so that the test framework still detects the error by running the callback in a nextTick() (or setImmediate() or setTimeout()) so that node-postgres' cleanup isn't aborted by the exception:

function runQuery ( sql, values, _cb ) {
    function cb ( ...args ) {
        process.nextTick(function() {
            _cb(...args);
        });
    }

    return pool.query(sql, values, cb);
}

@charmander:

Resuming after uncaughtException isn’t normal

It isn't normal in a production context, but it is normal in a testing context (mocha does this and I believe jest does as well).

pg can probably do something to clean up after uncaught exceptions in callbacks anyway
(Or get rid of callbacks and require promises in a future version?)

I do think this will go away once everyone migrates away from callbacks, but for large, feature-complete codebases, that migration may take a long time or may never make sense from a cost/benefit perspective.

IMO, it would be better if node-postgres did the necessary cleanup regardless of an exception being thrown in the callback. This could be done by catching the error and re-throwing it after the cleanup is done, or by calling the callback in a process.nextTick() (or setImmediate() or setTimeout()). Would you be open to a pull request along these lines? If so, do you have a preference regarding re-throwing vs nextTick() vs setImmediate()?

prust added a commit to CSNW/node-postgres that referenced this issue May 31, 2022
@prust
Fix brianc#2556 (handleRowDescription of null) by keeping callback er…
c9f9caf 
…rors from interfering with cleanup
prust added a commit to CSNW/node-postgres that referenced this issue May 31, 2022
@prust
Added regression test for brianc#2556
005047f
prust added a commit to CSNW/node-postgres that referenced this issue May 31, 2022
@prust
Added regression test for brianc#2556
67f2b45
@prust prust mentioned this issue May 31, 2022
Merged
brianc pushed a commit that referenced this issue Jun 20, 2022
@prust
Fix #2556 by keeping callback errors from interfering with cleanup (#…
68160a2 
…2753)

* Fix #2556 (handleRowDescription of null) by keeping callback errors from interfering with cleanup

* Added regression test for #2556
@alxndrsn alxndrsn mentioned this issue Aug 5, 2022
Merged
@kdhkr kdhkr mentioned this issue Jan 2, 2023
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
waiting for more info
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix #2556 by keeping callback errors from interfering with cleanup CSNW/node-postgres
7 participants
@prust @brianc @charmander @dhenson02 @liam-lai @repl-chris @SergeiLL