100% CPU usage if admin port is not free while ProxySQL is started

[canozokur]

Hello,

ProxySQL version: 1.3.3-0-gf2b677a and 1.3.2-1-gd71a745
on CentOS 7

If the admin port (default 6032) is used by another process, ProxySQL seems to use 100% cpu after startup. Also if the port becomes free afterwards, it doesn't recover.

You can reproduce it easily by using netcat or something similar. Using netcat, bind to port 6032;

# nc -l 6032

Then on another shell start ProxySQL. You should see ProxySQL consuming 100% cpu.

Maybe we're polling for the socket to become free too often? If I strace the process, lots and lots of these show up:

# strace -f -p 922

[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68132394}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68178998}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68299246}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68346321}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68467146}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68513571}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68633876}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68680480}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68800095}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68846899}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 68963935}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69025960}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69164797}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69211979}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69333150}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69379451}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69499944}) = 0
[pid   922] clock_gettime(CLOCK_MONOTONIC, {3629662, 69546549}) = 0
[pid   922] poll([{fd=3, events=POLLIN}, {fd=35, events=POLLIN}, {fd=37, events=POLLIN}], 3, 500) = 1 ([{fd=35, revents=POLLHUP}])

I've checked fd=37 and that's proxysql_admin.sock, I believe fd=35 is the tcp socket. I can't find that inode in the tcp connections though.

Thanks! :)

[renecannao]

Hi Can,

Thank you for the report.
I haven't test it yet, but I think it is spinning here: https://github.com/sysown/proxysql/blob/1.3.3/lib/ProxySQL_Admin.cpp#L2698

I will look further into it.
Thanks

[renecannao]

Error EADDRINUSE wasn't correctly handled, and Admin was entering an infinite loop

[renecannao]

Fixed in 1.3.4 (soon to be released) and 1.4.0