TypeError: Cannot read property 'name' of null

First off, thanks for the library! Overall it's been incredibly performant and straightforward to use. I am running into one issue which may be an issue with the library, though it's a bit hard to follow the protocol for me so my usage may be off as well.

I'm running into an uncaught error during the parseComplete handler in client.js (https://github.com/brianc/node-postgres/blob/v6.0.1/lib/client.js#L131).

I am doing a direct connect against the pool and then utilizing pg-query-stream

pool.connect().then(function(client){
  stream = client.query(new QueryStream(query, null));

  stream.on('error', function(streamError){
    stream.close(function(closeError){ 
      // What to do with a close error? At this point stream is already hosed :shrug:
      client.release(streamError);
    }
  });

  stream.on('close', function(){
    client.release();
  }); 
});

At some point during my app's life cycle, I get an uncaught error

TypeError: Cannot read property 'name' of null
    at null.<anonymous> (/var/app/current/node_modules/pg/lib/client.js:139:26)
    at emit (events.js:107:17)
    at Socket.<anonymous> (/var/app/current/node_modules/pg/lib/connection.js:121:12)
    at Socket.emit (events.js:107:17)
    at readableAddChunk (_stream_readable.js:163:16)
    at Socket.Readable.push (_stream_readable.js:126:10)
    at TCP.onread (net.js:540:20)

So obviously activeQuery is becoming null, and I am trying to narrow down why I would receive a parseComplete event when the active query is null.

According to my logs, the stream is not emitting an error, and seems to be closing normally. Therefore it seems like the connection client is getting a readyForQuery or end event, and then right after that getting the parseComplete event. Any idea why this would be happening, or see any issues with my usage? Thanks for any help you can give! I'll keep looking into it as well.

@greghart

@greghart interesting error - any way you could include the query & some data so I could try to reproduce it here? Maybe using generate_series or something if you need lots of data?

I've been having the same issue but only on my live site, once every few hours.
My logs would always show that I received 2 requests to run the same query within about 5 ms - always 1 after another (no other queries in between).
I don't know if the parameters are the same because I don't log them.

One would then get executed and the second would crash.
It would usually happen again within a minute if I attempted to restart that application without restarting all the others that communicated with it. Basically, some combination of requests caused the issue to appear.

I haven't been able to replicate this offline.
To me at this point, it looks like a race condition and maybe some kind of reference error (destroying the activeQuery on the wrong client).

I switched to pg-native and the problem appears to have stopped (over 12 hours with no issues).

Having this issue. I had switched away from pg-native cause it was giving headache as well.

Only happens on first-start. The second time pg is used, the error goes away. The "race" condition is that it happens always at first.

So part of our production push right now is to hit the servers ourselves first before we let users use them so they don't get this error. Which is a hack of a fix.

Anyone was able to fix this?

Just had this issue occur with connect-pg-simple configured pretty much as described in the advanced example of https://github.com/voxpelli/node-connect-pg-simple#usage.

@nemo

Do any of y'all have a small script I can use that will likely reproduce this? Also are you using pg or pg-native? This is really perplexing but really crappy & I want to get it fixed if possible. I've used node-postgres for years on many systems in production and never seen this...so I'm not sure what exactly it could be.

@nemo gah that fix is gross - sorry you have to do that. You're using normal pg and what exact version of node are you using?

@brianc

My application (very rarely) has experienced this problem as well. We have unfortunately been unable to distill it down to a simple script/app that can reliably reproduce, but general observation so far seems to indicate this happens when there is a connection issue with the database.

@brianc : I can completely understand the need to be able to reproduce in order to fix - but what are your thoughts on a short term fix to at least check to make sure activeQuery is a valid object before trying to reference the name property? Given the inability for client applications to handle this error in any way... and its drastic consequences - would be great if some form of incremental improvement could be delivered...

https://github.com/brianc/node-postgres/blob/master/lib/client.js#L241 indicates access to the name attribute allows to avoid the client from re-parsing the query. I would much rather take extraneous reparsing when the alternative is uncaught exception 😇

@andyatmiami

@andyatmiami - what version of pg & pg-pool are you using? Are you using pg-cursor or pg-query-stream?

"pg": "6.1.2"
"pg-pool": "1.6.0"
"node": "6.11.1"

We use parameterized queries exclusively.

FWIW:
I have a dev I am working with this afternoon who has had minimal success reproducing this - not yet reliable and not yet distilled into a simple app to run. At a high level (which I am working on refining) - we have 1 wildly expensive query (takes seconds to run), and then hammer a high load of other queries which are not long-running in parallel. Sometimes (and this is with Postgres completely stable) we see the activeQuery error fire...

Yah that's wretched that its happening. I really hope you can figure out a reproducible test case. I'd also suggest trying with the most recent version of pg & pg-pool. They both received pretty substantial internals upgrades from 6.x -> 7.x & 1.x -> 2.x respectively.

@brianc

@brianc : Thanks for responsiveness in issue - will post back any updates/learnings as they come available!

@spollack

I get the same error and also sometimes a different stack which I am guessing points to the same root cause

    self.activeQuery.handleCommandComplete(msg, con)
                    ^

TypeError: Cannot read property 'handleCommandComplete' of null
    at Connection.<anonymous> (/home/app/node_modules/pg/lib/client.js:239:21)
    at emitOne (events.js:96:13)
    at Connection.emit (events.js:188:7)
    at Socket.<anonymous> (/home/app/node_modules/pg/lib/connection.js:118:12)
    at emitOne (events.js:96:13)
    at Socket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at Socket.Readable.push (_stream_readable.js:134:10)
    at TCP.onread (net.js:547:20)
events.js:160
      throw er; // Unhandled 'error' event

I see there was pull request from @spollack (#961) around this . @spollack, @jshepard it was mentioned in the PR that there was an another library causing this, do you mind sharing your findings ?

I'm also using query_timeout:

[2019-07-11 09:36:36] [ERROR] [pid:8718] TypeError: Cannot read property 'name' of null
TypeError: Cannot read property 'name' of null
at Connection. (/opt/acn/4be1e1fb/api/node_modules/pg/lib/client.js:313:26)
at emitOne (events.js:116:13)
at Connection.emit (events.js:211:7)
at Socket. (/opt/acn/4be1e1fb/api/node_modules/pg/lib/connection.js:126:12)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at addChunk (_stream_readable.js:263:12)
at readableAddChunk (_stream_readable.js:250:11)
at Socket.Readable.push (_stream_readable.js:208:10)
at TCP.onread (net.js:597:20)

I was experiencing this issue with pg-query-stream and downgrading to [email protected] fixed it. Not sure what changed but maybe that is something to look into?

I'm also using [email protected] with [email protected]. I tried downgrading pg-promise to a version that uses [email protected] based on the previous comment, but it did not fix the issue.

Unfortunately, I only encounter this issue when running some automated tests in a docker container (CentOS 7.6.1810). Things run noticeably slower in the container vs locally (MacOS 10.14.6) so maybe it's timing related as mentioned above. In all cases, the database is running in a separate container (PostgreSQL 11.5 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 7.3.1 20180303 (Red Hat 7.3.1-5), 64-bit).

If it's at all helpful, here's the test code that fails:

let errorEncountered = false;
let results;
try {
    results = await runQuery('SELECT * FROM nonexistant_table');
} catch (err) {
    errorEncountered = true;
    expect(err).to.exist;
    expect(err.message).to.equal('relation "nonexistant_table" does not exist');
}

expect(errorEncountered).to.be.true;

// Reaches here
results = await runQuery('SELECT * FROM good_table WHERE id >= 18 ORDER BY id DESC;');
// Does not reach here

expect(results).to.have.lengthOf(4);
expect(results[2].id).to.equal(19);

runQuery() sends the query to the server via a web socket request and receives the data in chunks. The function resolves when the query has completed.

Here's a much simplified version of my server code:

function executeQuery(query) {
    return new Promise((resolve, reject) => {
        connection.task(async tx => {
            await tx.none('SET <custom_config_key>=<custom_config_value>');

            return tx.stream(queryStream, function (stream) {
                stream.pipe(outputStream);
                
                stream.on('error', err => {
                    outputStream.emit('error', err);
                });

                // Resolve now that the stream has been initiated.
                resolve();
            });
        }).catch(err => {
            reject(err);
        });
    });
}

webSocketRequestHandler(query) {
    const outputStream = new PassThrough({ objectMode: true });

    // Add some stream listeners

    executeQuery(query).then(() => {
        // Send data back to the client in chunks as data comes through the stream
    });
}

The failure happens reliably every time I run the tests, so if there's some places I can add log statements to better track down this problem, I am happy to assist.

After reading this comment and some more experimentation, I seem to have gotten around this problem by making sure the stream is closed before releasing the connection back to the pool.

function executeQuery(query) {
    return new Promise((resolve, reject) => {
        connection.task(async tx => {
            await tx.none('SET <custom_config_key>=<custom_config_value>');
    
            return new Promise((connResolve, connReject) => {
                return tx.stream(queryStream, function (stream) {
                    stream.on('close', () => {
                        // Make sure the stream is closed before releasing the connection back to the connection pool
                        connResolve();
                    });
                    stream.on('error', err => {
                        outputStream.emit('error', err);
                    });
                    stream.pipe(outputStream);

                    // Resolve now that the stream has been initiated.
                    resolve();
                });
            });
        }).catch(err => {
            reject(err);
        });
    });
}

I'm not sure where the right place to make the change would be, but it seems like maybe this safeguard could be added to one of the involved libraries (pg-pool or pg-promise?) so a close listener wouldn't be necessary externally...?

Also, I feel like it's worth mentioning that I initially got around this error by commenting out this line in pg-cursor/index.js. Probably not the best idea to do that, but it helped me figure things out.

For those of you catching this with statement timeouts: I was able to reproduce this error consistently when statement_timeout and query_timeout were set to the same value. Increasing query_timeout relative to statement_timeout seems to improve the frequency at which we see this error

I have a PR up for this: #2367. The fix feels dirty to me, but I think what's happening here might be a race condition within postgres itself we're working around.

@brianc

FYI @brianc we did see this on postgres 12.3, not 9.x

@pvatterott

@pvatterott that's good to know, but a bummer as my hunch was around a race condition in older versions of postgres. I've been going back and forth w/ some postgres maintainers & think this might fix it. I can confirm it fixes in 9.x & 10.x of postgres, it might fix it for 12.3 of postgres as well. The change involves pipelining the sync command in with the other extended query commands all at once. It also improves my benchmarks by up to 10% in some cases, which is a nice side effect.

@brianc

Thank you @brianc !

Upgrade pg dependencies as of potential fix for brianc/node-postgres#…

@pckilgore

@pckilgore my pleasure! Let me know if it still happens...was quite a monster to track down but @timotm is the real hero here. Steps to reproduce & deep analysis helped me know where to focus. I regret it took me so long to circle back to this issue.

Hello,
I am still running this issue randomly when I do a qs.destroy();
I posted a full example of the situation here : https://stackoverflow.com/questions/61323787/pg-promise-cancel-a-query-initiated-with-pg-query-stream
While I posted this 10 months ago, I still have this issue with the latest lib.
I am facing this under PostgreSQL 12. Same error occured on PostgreSQL 10.
The main issue is that I can't even find a workaround or catch the error, it crash the whole app.

Upgrade pg dependencies as of potential fix for brianc/node-postgres#…

Navigation Menu

Repository navigation

TypeError: Cannot read property 'name' of null #1105

42 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

TypeError: Cannot read property 'name' of null #1105

Description

Activity

vitaly-t commented on Aug 10, 2016

brianc commented on Aug 10, 2016

dynajoe commented on Feb 24, 2017

dynajoe commented on Feb 24, 2017

charmander commented on Feb 25, 2017

jordandouglaswhite commented on Feb 26, 2017

nemo commented on Mar 5, 2017

hvrauhal commented on Apr 7, 2017

brianc commented on May 24, 2017

andyatmiami commented on Aug 28, 2017

brianc commented on Aug 28, 2017

andyatmiami commented on Aug 28, 2017

brianc commented on Aug 28, 2017

andyatmiami commented on Aug 29, 2017

vedant15 commented on Aug 30, 2017

42 remaining items

juliusza commented on Jul 11, 2019

emhagman commented on Jul 23, 2019

iancamp commented on Nov 5, 2019

iancamp commented on Nov 6, 2019

pvatterott commented on Sep 9, 2020

brianc commented on Oct 7, 2020

pvatterott commented on Oct 8, 2020

brianc commented on Oct 8, 2020

pckilgore commented on Oct 9, 2020

brianc commented on Oct 9, 2020

Raphyyy commented on Feb 25, 2021

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions