[MDEV-26440] Missing connection id value in I_S.thread_pool_queues Created: 2021-08-19  Updated: 2021-08-19  Resolved: 2021-08-19

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.5.10, 10.5.11, 10.5.12
Fix Version/s: 10.5.13, 10.6.5

Type: Bug Priority: Major
Reporter: Alex Sladkov Assignee: Vladislav Vaintroub
Resolution: Fixed Votes: 0
Labels: None

Attachments: File test-in-contaner.sh     File thread-pool-queues.sh    
Issue Links:
Relates
relates to MDEV-24757 Potential null pointer dereference in... Closed

 Description   

As far as I can tell, column I_S.thread_pool_queues.connection_id is supposed to contain ids of connections that are waiting for available worker threads.
The issue is that I haven't observed any values in this column besides NULL.
That makes it not quite possible to discern connections that are really sleeping from those that have queued queries.

Can be reproduced using official docker image.

MARIADB_VERSION=10.5.12 ./test-in-contaner.sh ./thread-pool-queues.sh > ./result.txt

Result:

cat result.txt 
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                      18301 |
|        0 |        1 |        0 |          NULL |                      16621 |
|        0 |        2 |        0 |          NULL |                      16214 |
|        0 |        3 |        0 |          NULL |                      15903 |
|        0 |        4 |        0 |          NULL |                      14968 |
|        0 |        5 |        0 |          NULL |                      14366 |
|        0 |        6 |        0 |          NULL |                      12835 |
|        0 |        7 |        0 |          NULL |                      11526 |
+----------+----------+----------+---------------+----------------------------+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        1 |          NULL |                      56000 |
|        0 |        1 |        1 |          NULL |                      56000 |
|        0 |        2 |        1 |          NULL |                      56000 |
|        0 |        3 |        1 |          NULL |                      56000 |
|        0 |        4 |        1 |          NULL |                      56000 |
|        0 |        5 |        1 |          NULL |                      56000 |
+----------+----------+----------+---------------+----------------------------+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        1 |          NULL |                    1068634 |
|        0 |        1 |        1 |          NULL |                    1068634 |
|        0 |        2 |        1 |          NULL |                    1068634 |
|        0 |        3 |        1 |          NULL |                    1068634 |
+----------+----------+----------+---------------+----------------------------+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    2081406 |
|        0 |        1 |        0 |          NULL |                    2081406 |
|        0 |        2 |        0 |          NULL |                    2081406 |
|        0 |        3 |        1 |          NULL |                     584074 |
|        0 |        4 |        1 |          NULL |                     584074 |
|        0 |        5 |        1 |          NULL |                     584074 |
|        0 |        6 |        1 |          NULL |                     466012 |
+----------+----------+----------+---------------+----------------------------+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    3093475 |
|        0 |        1 |        0 |          NULL |                    1596143 |
|        0 |        2 |        0 |          NULL |                    1596143 |
|        0 |        3 |        0 |          NULL |                    1596143 |
|        0 |        4 |        0 |          NULL |                    1478081 |
|        0 |        5 |        1 |          NULL |                     920131 |
|        0 |        6 |        1 |          NULL |                     460330 |
+----------+----------+----------+---------------+----------------------------+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    2608249 |
|        0 |        1 |        0 |          NULL |                    2608249 |
|        0 |        2 |        0 |          NULL |                    2490187 |
|        0 |        3 |        0 |          NULL |                    1932237 |
|        0 |        4 |        0 |          NULL |                    1472436 |
|        0 |        5 |        1 |          NULL |                     836087 |
|        0 |        6 |        1 |          NULL |                     345225 |
+----------+----------+----------+---------------+----------------------------+



 Comments   
Comment by Vladislav Vaintroub [ 2021-08-19 ]

As far as I can tell, it will show you connection ids when those are available. If you get NULL, connection initialization (authentication and so on) did not yet succeed, and connection is not in the the list which is shown in "show processlist". Connections that are really sleeping are not part of any theadpool queues, but "show processlist", or corresponding information_schema.processlist table will show them with status Sleep , see e.g https://stackoverflow.com/q/12194241/547065

Comment by Alex Sladkov [ 2021-08-19 ]

it will show you connection ids when those are available

I'm inclined to believe this is not always the case.

If we add output of show processlist to thread-pool-queues.sh script,

-while $MYSQL_VIA_EXTRA_PORT -e 'SELECT ID FROM INFORMATION_SCHEMA.PROCESSLIST WHERE ID != CONNECTION_ID()' | grep -q '.*' ; do
+while $MYSQL_VIA_EXTRA_PORT -t -e 'SELECT * FROM INFORMATION_SCHEMA.PROCESSLIST WHERE ID != CONNECTION_ID()' | grep '.*' ; do

the result becomes like this

+----+------+-----------------+------+---------+------+-------+-------------------------+---------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+---------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
|  9 | root | 127.0.0.1:41848 | NULL | Sleep   |    0 |       | NULL                    |   6.918 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 195 |
|  8 | root | localhost:41846 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |   6.622 |     0 |         0 |    0.000 |       75976 |           75976 |             0 |    21183 | CALL test.spin(1000000) | 179 |
|  7 | root | 127.0.0.1:41844 | NULL | Sleep   |    0 |       | NULL                    |   6.642 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 179 |
|  6 | root | 127.0.0.1:41842 | NULL | Sleep   |    0 |       | NULL                    |   8.175 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 179 |
|  5 | root | localhost:41840 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |   6.898 |     0 |         0 |    0.000 |       75904 |           75904 |             0 |    21204 | CALL test.spin(1000000) | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+---------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                       5302 |
|        0 |        1 |        1 |          NULL |                      15970 |
|        0 |        2 |        1 |          NULL |                      10693 |
|        0 |        3 |        1 |          NULL |                       5545 |
|        0 |        4 |        1 |          NULL |                       4527 |
|        0 |        5 |        1 |          NULL |                       2721 |
|        0 |        6 |        1 |          NULL |                        438 |
+----------+----------+----------+---------------+----------------------------+
 
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS  | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| 15 | root | 127.0.0.1:41860 | NULL | Sleep   |    1 |       | NULL                    | 1010.088 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 14 | root | 127.0.0.1:41858 | NULL | Sleep   |    1 |       | NULL                    | 1011.533 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 13 | root | 127.0.0.1:41856 | NULL | Sleep   |    1 |       | NULL                    | 1013.235 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 12 | root | 127.0.0.1:41854 | NULL | Sleep   |    1 |       | NULL                    | 1016.408 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 10 | root | 127.0.0.1:41850 | NULL | Sleep   |    1 |       | NULL                    | 1017.544 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
|  9 | root | 127.0.0.1:41848 | NULL | Sleep   |    1 |       | NULL                    | 1028.052 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 195 |
|  8 | root | localhost:41846 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1027.756 |     0 |         0 |    0.000 |       75976 |           75976 |             0 |  5237951 | CALL test.spin(1000000) | 179 |
|  7 | root | 127.0.0.1:41844 | NULL | Sleep   |    1 |       | NULL                    | 1027.776 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 179 |
|  6 | root | localhost:41842 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1010.062 |     0 |         0 |    0.000 |       75976 |           75976 |             0 |  5237975 | CALL test.spin(1000000) | 196 |
|  5 | root | localhost:41840 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1028.032 |     0 |         0 |    0.000 |       75904 |           75904 |             0 |  5237986 | CALL test.spin(1000000) | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        1 |          NULL |                    1050922 |
|        0 |        1 |        1 |          NULL |                    1045774 |
|        0 |        2 |        1 |          NULL |                    1044756 |
|        0 |        3 |        1 |          NULL |                    1042950 |
|        0 |        4 |        1 |          NULL |                    1040667 |
|        0 |        5 |        1 |          NULL |                    1039285 |
|        0 |        6 |        1 |          NULL |                    1038386 |
+----------+----------+----------+---------------+----------------------------+
 
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS  | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| 15 | root | 127.0.0.1:41860 | NULL | Sleep   |    2 |       | NULL                    | 2063.289 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 14 | root | 127.0.0.1:41858 | NULL | Sleep   |    2 |       | NULL                    | 2064.734 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 13 | root | 127.0.0.1:41856 | NULL | Sleep   |    2 |       | NULL                    | 2066.436 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 12 | root | localhost:41854 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |  279.281 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 10522800 | CALL test.spin(1000000) | 195 |
| 10 | root | localhost:41850 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |  297.449 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 10522813 | CALL test.spin(1000000) | 196 |
|  9 | root | localhost:41848 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |  330.647 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 10522826 | CALL test.spin(1000000) | 179 |
|  8 | root | 127.0.0.1:41846 | NULL | Sleep   |    0 |       | NULL                    |  331.299 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |       50 | NULL                    | 179 |
|  7 | root | 127.0.0.1:41844 | NULL | Sleep   |    2 |       | NULL                    | 2080.977 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 179 |
|  6 | root | 127.0.0.1:41842 | NULL | Sleep   |    0 |       | NULL                    |  297.532 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |    54180 | NULL                    | 196 |
|  5 | root | 127.0.0.1:41840 | NULL | Sleep   |    0 |       | NULL                    |  279.339 |     0 |         0 |    0.000 |       74064 |           75904 |             0 |        5 | NULL                    | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    2080790 |
|        0 |        1 |        0 |          NULL |                    2078507 |
|        0 |        2 |        0 |          NULL |                    2077125 |
|        0 |        3 |        0 |          NULL |                    2076226 |
|        0 |        4 |        1 |          NULL |                     343666 |
|        0 |        5 |        1 |          NULL |                     309937 |
|        0 |        6 |        1 |          NULL |                     291611 |
+----------+----------+----------+---------------+----------------------------+
 
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS  | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| 15 | root | 127.0.0.1:41860 | NULL | Sleep   |    3 |       | NULL                    | 3083.463 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 14 | root | 127.0.0.1:41858 | NULL | Sleep   |    3 |       | NULL                    | 3084.908 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 13 | root | 127.0.0.1:41856 | NULL | Sleep   |    3 |       | NULL                    | 3086.610 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 12 | root | localhost:41854 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1299.455 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 15765328 | CALL test.spin(1000000) | 195 |
| 10 | root | localhost:41850 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1317.623 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 15765338 | CALL test.spin(1000000) | 196 |
|  9 | root | localhost:41848 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1350.821 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 15765351 | CALL test.spin(1000000) | 179 |
|  8 | root | 127.0.0.1:41846 | NULL | Sleep   |    1 |       | NULL                    | 1351.473 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |       50 | NULL                    | 179 |
|  7 | root | 127.0.0.1:41844 | NULL | Sleep   |    3 |       | NULL                    | 3101.151 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 179 |
|  6 | root | 127.0.0.1:41842 | NULL | Sleep   |    1 |       | NULL                    | 1317.706 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |    54180 | NULL                    | 196 |
|  5 | root | 127.0.0.1:41840 | NULL | Sleep   |    1 |       | NULL                    | 1299.513 |     0 |         0 |    0.000 |       74064 |           75904 |             0 |        5 | NULL                    | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    3100883 |
|        0 |        1 |        0 |          NULL |                    3098600 |
|        0 |        2 |        0 |          NULL |                    3097218 |
|        0 |        3 |        0 |          NULL |                    3096319 |
|        0 |        4 |        0 |          NULL |                    1363759 |
|        0 |        5 |        1 |          NULL |                    1330030 |
|        0 |        6 |        1 |          NULL |                    1311704 |
+----------+----------+----------+---------------+----------------------------+
 
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS  | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| 15 | root | 127.0.0.1:41860 | NULL | Sleep   |    4 |       | NULL                    | 4117.876 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 14 | root | localhost:41858 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |  576.792 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 21034487 | CALL test.spin(1000000) | 195 |
| 13 | root | localhost:41856 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |  607.875 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 21034941 | CALL test.spin(1000000) | 196 |
| 12 | root | 127.0.0.1:41854 | NULL | Sleep   |    0 |       | NULL                    |  576.844 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |  9115891 | NULL                    | 195 |
| 10 | root | 127.0.0.1:41850 | NULL | Sleep   |    0 |       | NULL                    |  607.927 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |  9025917 | NULL                    | 196 |
|  9 | root | 127.0.0.1:41848 | NULL | Sleep   |    0 |       | NULL                    |  624.182 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |  8861726 | NULL                    | 179 |
|  8 | root | 127.0.0.1:41846 | NULL | Sleep   |    2 |       | NULL                    | 2385.886 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |       50 | NULL                    | 179 |
|  7 | root | localhost:41844 | test | Query   |    0 | NULL  | CALL test.spin(1000000) |  624.115 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 21028113 | CALL test.spin(1000000) | 179 |
|  6 | root | 127.0.0.1:41842 | NULL | Sleep   |    2 |       | NULL                    | 2352.119 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |    54180 | NULL                    | 196 |
|  5 | root | 127.0.0.1:41840 | NULL | Sleep   |    2 |       | NULL                    | 2333.926 |     0 |         0 |    0.000 |       74064 |           75904 |             0 |        5 | NULL                    | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    4131844 |
|        0 |        1 |        0 |          NULL |                    2399284 |
|        0 |        2 |        0 |          NULL |                    2365555 |
|        0 |        3 |        0 |          NULL |                    2347229 |
|        0 |        4 |        1 |          NULL |                     637590 |
|        0 |        5 |        1 |          NULL |                     621483 |
|        0 |        6 |        1 |          NULL |                     590380 |
+----------+----------+----------+---------------+----------------------------+
 
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS  | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| 15 | root | 127.0.0.1:41860 | NULL | Sleep   |    5 |       | NULL                    | 5145.195 |     0 |         0 |    0.000 |       74904 |           74904 |             0 |        0 | NULL                    | 196 |
| 14 | root | localhost:41858 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1604.111 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 26326431 | CALL test.spin(1000000) | 195 |
| 13 | root | localhost:41856 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1635.194 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 26326443 | CALL test.spin(1000000) | 196 |
| 12 | root | 127.0.0.1:41854 | NULL | Sleep   |    1 |       | NULL                    | 1604.163 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |  9115891 | NULL                    | 195 |
| 10 | root | 127.0.0.1:41850 | NULL | Sleep   |    1 |       | NULL                    | 1635.246 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |  9025917 | NULL                    | 196 |
|  9 | root | 127.0.0.1:41848 | NULL | Sleep   |    1 |       | NULL                    | 1651.501 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |  8861726 | NULL                    | 179 |
|  8 | root | 127.0.0.1:41846 | NULL | Sleep   |    3 |       | NULL                    | 3413.205 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |       50 | NULL                    | 179 |
|  7 | root | localhost:41844 | test | Query   |    1 | NULL  | CALL test.spin(1000000) | 1651.434 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 26326494 | CALL test.spin(1000000) | 179 |
|  6 | root | 127.0.0.1:41842 | NULL | Sleep   |    3 |       | NULL                    | 3379.438 |     0 |         0 |    0.000 |       74064 |           75976 |             0 |    54180 | NULL                    | 196 |
|  5 | root | 127.0.0.1:41840 | NULL | Sleep   |    3 |       | NULL                    | 3361.245 |     0 |         0 |    0.000 |       74064 |           75904 |             0 |        5 | NULL                    | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+----------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        0 |          NULL |                    5157136 |
|        0 |        1 |        0 |          NULL |                    3424576 |
|        0 |        2 |        0 |          NULL |                    3390847 |
|        0 |        3 |        0 |          NULL |                    3372521 |
|        0 |        4 |        0 |          NULL |                    1662882 |
|        0 |        5 |        0 |          NULL |                    1646775 |
|        0 |        6 |        0 |          NULL |                    1615672 |
+----------+----------+----------+---------------+----------------------------+
 
+----+------+-----------------+------+---------+------+-------+-------------------------+---------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| ID | USER | HOST            | DB   | COMMAND | TIME | STATE | INFO                    | TIME_MS | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | MAX_MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY             | TID |
+----+------+-----------------+------+---------+------+-------+-------------------------+---------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
| 15 | root | localhost:41860 | test | Query   |    0 | NULL  | CALL test.spin(1000000) | 920.890 |     0 |         0 |    0.000 |       75976 |           75976 |             0 | 28644753 | CALL test.spin(1000000) | 196 |
| 14 | root | 127.0.0.1:41858 | NULL | Sleep   |    0 |       | NULL                    | 825.878 |     0 |         0 |    0.000 |       74064 |           75976 |             0 | 18138272 | NULL                    | 195 |
+----+------+-----------------+------+---------+------+-------+-------------------------+---------+-------+-----------+----------+-------------+-----------------+---------------+----------+-------------------------+-----+
+----------+----------+----------+---------------+----------------------------+
| GROUP_ID | POSITION | PRIORITY | CONNECTION_ID | QUEUEING_TIME_MICROSECONDS |
+----------+----------+----------+---------------+----------------------------+
|        0 |        0 |        1 |          NULL |                     833917 |
+----------+----------+----------+---------------+----------------------------+

Here we can see that USER column is non-empty, so connection initialization has probably completed, and also we can see very suspicious correlation between INFORMATION_SCHEMA.PROCESSLIST.TIME_MS and INFORMATION_SCHEMA.THREAD_POOL_QUEUES.QUEUEING_TIME_MICROSECONDS values.
Because of that I think that these connections are in fact already in queue for query execution, but CONNECTION_ID for some reason is still showing NULL.

Comment by Vladislav Vaintroub [ 2021-08-19 ]

After some debugging, yes you're right, there is a bug in there.

Althought I'm still not getting your example, it uses the command line client to connect, execute a single query then disconnect.

A better example would need all clients to connect, then simultaneously execute some long query, then disconnect.
I'll try to come up with multithreading test, using more standard techniques, i.e mysql-test-run
and long SELECT SLEEP() queries to emulate blocking

Comment by Alex Sladkov [ 2021-08-19 ]

Althought I'm still not getting your example, it uses the command line client to connect, execute a single query then disconnect.

A better example would need all clients to connect, then simultaneously execute some long query, then disconnect.

My example in fact does run the long commands in parallel.
It would be certainly better to do as you suggest, but it's a bit tricky to do in a simple shell script, and I wasn't aware that mysql-test-run exists (by the way, thank you for teaching me about that!).
Also, I wasn't sure if SELECT SLEEP() actually blocks its thread, so I wrote that clumsy procedure to emulate blocking, but apparently it wasn't necessary.

Generated at Thu Feb 08 09:45:19 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.