Parsing single result with large amount of columns takes more time in 8.11.3

[wannabehero]

Most likely is the direct consequence of #3043

After upgrading to 8.11.3 we've started to experience the increased latency for one of our queries:

The graph shows latency at 8.11.2, then 8.11.3 (increased), and then after we rolled back to 8.11.2. No other dependencies were changed. We also use typeorm on top of pg.

This query fetched 1 row but with ~600 columns. All other queries were not affected this much.

We isolated the issue to the query call (pganalyze didn't show any difference in the actual query time, also nothing else was changed in the code).

What we believe is happening: because of the extra loop for pre-building an empty object it adds some execution time.

We've prepared some sample code to showcase the issue: https://gist.github.com/wannabehero/a6531df714041e559a38c97d49f2f444

➜  pg-test node test.js
8.11.3: 164.089ms
8.11.2: 80.921ms

Do you think it's valid? If so, can we get back to having an option to enable this behavior? Like it was in 11955a0

Thanks.

[brianc]

@wannabehero oh yup I could see an additional loop slowing it down. You wanna test out the PR I put up on #3056 ? It removes the additional loop (we were already looping on rowDescription anyway, so I just use the same loop now).

[charmander]

A difference of tens of milliseconds (in the graph), for making an object with just 600 null properties? Is that an aggregate time for multiple runs of this one-row query? Or is it maybe the shape difference(?) having an unexpected effect on how you use the result?

[wannabehero]

@charmander we use datadog to collect pg metrics that I included in the issue.

Datadog wraps the query method
https://github.com/DataDog/dd-trace-js/blob/master/packages/datadog-instrumentations/src/pg.js

And the only difference between 8.11.2 and 8.11.3 is the extra loop and the pre-built object.

[wannabehero]

@brianc thanks for the swift response❤️

We should be able to validate early next week. I'll get back as soon as we do

[brianc]

Awesome! Thanks!

…

On Sat, Sep 2, 2023 at 4:15 AM Sergey Pronin ***@***.***> wrote: @brianc <https://github.com/brianc> thanks for the swift response❤️ We should be able to validate early next week. I'll get back as soon as we do — Reply to this email directly, view it on GitHub <#3055 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAAMHIKKUCYHYDDUOQEV6RDXYL2LPANCNFSM6AAAAAA4HYEVJM> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[wannabehero]

Hi @brianc

I run the same small experiment over the updated code from #3056: https://gist.github.com/wannabehero/0ec140e764413624a89004af13de7fc2

➜  pg-test node test2.js
8.11.2: 63.964ms
8.11.3: 126.89ms
8.11.4: 125.591ms

I think I've figured it out: extra loop is not a problem but building a row with

var row = {}
for (var i = 0; i < fields.length; i++) {
  row[fields[i].name] = null
}

apparently takes extra time.

During my experiments I found that using Map takes less time to fill it with nulls, but then you can't really do {...mapObject} so it lead to nowhere.

Maybe consider adding a config flag after all?