CPU usage spikes and remains at 100%

[rogerho1224]

Flagging that our team experienced this issue recently - #1432

We reproduced this with mysql2 versions 2.3.1, 2.3.3, and 3.3.5.

Node Version: 18.16.0
Local Machine: Macbooks running Ventura 13.0.1.
Server Machine: Ubuntu (i can get the version if necessary)

Details:
One of our endpoints joins multiple tables and selects over 400 columns in aggregate from these tables. We're able to reproduce the issue of cpu usage going to 100% and staying there for some time pretty consistently by issuing 10+ network requests to our endpoint in quick succession. Some of the columns are TEXT columns if that's pertinent.

We've downgraded to 2.3.0 in the meantime, but would love to be able to get back on the latest versions. In particular, being able to use escape / escapeId through a pool without obtaining a connection is important to us.

Appreciate your help on this one!

[sidorares]

Hi @rogerho1224 , if you could create a self contained repro that you can share with me that would really simplify debugging

Alternatively, you can start your server with V8 profiler attached and we could have a look at the hot part of the profiler log together

[rogerho1224]

Thanks for the quick reply @sidorares. Let's try the second option before the first. It's difficult to duplicate the columns and rows in our db in a way that obscures customer data

Could you go into a bit more detail on how you'd like me to start my server and record logs? During our debugging process we already tried profiling CPU / Heap in the method outlined here but the logs didn't match the CPU usage stated by Activity Monitor / kubernetes top

[sidorares]

try with node --prof yourserver.js
This will generate a sample based profile log that in turn can be converted into call trees with node --prof-process

See more at https://nodejs.org/en/docs/guides/simple-profiling

[rogerho1224]

https://pastebin.com/xJemRNDK

We tried that as well during our debugging. The output wasn't useful to me but let me know what you think.

My steps:

1. node --prof my_server.js
2. Issue some network requests to my endpoint that queries our SQL db
3. Watch CPU usage spike to 100% on activity monitor and sustain
4. Wait a bit, then kill node process
5. node --prof-process the generated log and paste to pastebin

One thing I noticed while testing is that if we select the entire contents of our db (200,000 rows / 249 columns) then I can get it to spike to 100% with just one query

[rogerho1224]

https://pastebin.com/9K6thV7U

Here is our schema with column names and indices removed

[sidorares]

Thanks, I'll have a look at the logs when I have a bit of free time!

One thing I noticed while testing is that if we select the entire contents of our db (200,000 rows / 249 columns) then I can get it to spike to 100% with just one query

is it just a temporary spike while data is received / deserialised or it stays like that for some time after?

200,000 rows / 249 columns is a lot of data, some CPU spike is expected. Also - how big are the columns typically?

[sidorares]

In the first pasted logfile:

(505 ticks, 9 unaccounted, 0 excluded)

This looks way too short, and mostly shows traces to load modules ( require / evaluate )
Maybe worth checking if your server spawns a child process and and you are profiling the correct one

[sidorares]

I wonder if its a side effect of 01485d5

also ref #2055

[sidorares]

I can try to create a branch to test a possible fix, would you able to try it with your setup @rogerho1224 ?

[rogerho1224]

CPU usage stays spiked for some time.

My server this time is very basic (express-generator) so I'm not sure if it'd be spinning up a child process.
var server = http.createServer(app); // Do you think this would be on the same process or different

I'd be delighted to test your branch. Let me know when it's up

[rogerho1224]

The VARCHAR(255) columns are usually 10-20 characters probably. The text columns can be a bit longer

[sidorares]

@rogerho1224 I'm very confident the root cause is the same as in #2090 ( likely a bug in V8 optimiser ). The solution on mysql2 side will be to avoid JIT generation of parser for a results with large number of rows. Closing this issue as a duplicate, please track the progress in #2090