[MDEV-8107] [Draft] Weird processlist Created: 2015-05-05  Updated: 2022-09-28  Resolved: 2022-09-26

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.1
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Elena Stepanova
Resolution: Incomplete Votes: 1
Labels: None


 Description    

+-----+-------------+-----------------+-------+---------+------+------------------------------------------------------+-------------------------------------------------+----------+
 
| Id  | User        | Host            | db    | Command | Time | State                                                | Info                                            | Progress |
 
+-----+-------------+-----------------+-------+---------+------+------------------------------------------------------+-------------------------------------------------+----------+
 
|   2 | root        | localhost:45762 | mysql | Query   |  328 | Waiting for the slave SQL thread to advance position | SELECT MASTER_POS_WAIT('mysql-bin.000021',2466) |    0.000 |
 
| 157 | system user |                 | NULL  | Connect |  328 | Waiting for master to send event                     | NULL                                            |    0.000 |
 
| 159 | system user |                 | NULL  | Connect |  776 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 160 | system user |                 | NULL  | Connect |  795 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 161 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 162 | system user |                 | NULL  | Connect |  795 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 163 | system user |                 | NULL  | Connect |  762 | Write_rows_log_event::write_row(-1)                  | NULL                                            |    0.000 |
 
| 164 | system user |                 | NULL  | Connect |  798 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 165 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 166 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 167 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 168 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 169 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 170 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 171 | system user |                 | NULL  | Connect |  776 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 172 | system user |                 | NULL  | Connect |  795 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 173 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 174 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 175 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 176 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 177 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 178 | system user |                 | NULL  | Connect |  328 | Waiting for work from SQL thread                     | NULL                                            |    0.000 |
 
| 179 | system user |                 | NULL  | Connect |    0 | Waiting for room in worker thread event queue        | NULL                                            |    0.000 |
 
| 180 | root        | localhost:48476 | test  | Query   |    0 | init                                                 | show processlist                                |    0.000 |
 
+-----+-------------+-----------------+-------+---------+------+------------------------------------------------------+-------------------------------------------------+----------+
 

+-----+-------------+-----------------+------+---------+------+-----------------------------------------------------------------------------+------------------+----------+
 
| Id  | User        | Host            | db   | Command | Time | State                                                                       | Info             | Progress |
 
+-----+-------------+-----------------+------+---------+------+-----------------------------------------------------------------------------+------------------+----------+
 
| 183 | root        | localhost:48711 | test | Query   |    0 | init                                                                        | show processlist |    0.000 |
 
| 242 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 243 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 244 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 245 | system user |                 | NULL | Connect |  104 | Update_rows_log_event::find_row(-1)                                         | NULL             |    0.000 |
 
| 246 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 247 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 248 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 249 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 250 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 251 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 252 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 253 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 254 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 255 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 256 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 257 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 258 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 259 | system user |                 | NULL | Connect |  131 | Delete_rows_log_event::ha_delete_row(-1)                                    | NULL             |    0.000 |
 
| 260 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 261 | system user |                 | NULL | Connect |   19 | Waiting for work from SQL thread                                            | NULL             |    0.000 |
 
| 262 | system user |                 | NULL | Connect |    8 | Slave has read all relay log; waiting for the slave I/O thread to update it | NULL             |    0.000 |
 
| 264 | system user |                 | NULL | Connect |    9 | Queueing master event to the relay log                                      | NULL             |    0.000 |
 
+-----+-------------+-----------------+------+---------+------+-----------------------------------------------------------------------------+------------------+----------+
 
23 rows in set (0.00 sec)

Same in I_S.processlist:

+-----+-------------+-----------------+------+---------+------+------------------------------------------------------------------+-----------------------------------------------+------------+-------+-----------+----------+-------------+---------------+----------+
 
| ID  | USER        | HOST            | DB   | COMMAND | TIME | STATE                                                            | INFO                                          | TIME_MS    | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | EXAMINED_ROWS | QUERY_ID |
 
+-----+-------------+-----------------+------+---------+------+------------------------------------------------------------------+-----------------------------------------------+------------+-------+-----------+----------+-------------+---------------+----------+
 
| 325 | system user |                 | NULL | Connect |    0 | Reading event from the relay log                                 | NULL                                          |     60.582 |     0 |         0 |    0.000 |       68808 |             0 |        0 |
 
| 324 | system user |                 | NULL | Connect |   71 | Waiting for prior transaction to start commit before starting ne | NULL                                          |  71047.208 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 323 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71047.679 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 322 | system user |                 | NULL | Connect |   71 | Waiting for prior transaction to start commit before starting ne | NULL                                          |  71048.035 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 321 | system user |                 | NULL | Connect |   71 | Waiting for prior transaction to start commit before starting ne | NULL                                          |  71048.216 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 320 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71048.323 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 319 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71048.519 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 318 | system user |                 | NULL | Connect |   71 | Waiting for prior transaction to start commit before starting ne | NULL                                          |  71048.562 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 317 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71048.513 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 316 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71048.882 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 315 | system user |                 | NULL | Connect |  241 | Update_rows_log_event::find_row(-1)                              | NULL                                          | 241975.688 |     0 |         0 |    0.000 |       52416 |             0 |     3129 |
 
| 314 | system user |                 | NULL | Connect |   71 | Waiting for prior transaction to start commit before starting ne | NULL                                          |  71049.196 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 313 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71049.354 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 312 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71049.498 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 311 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71049.576 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 310 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71049.637 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 309 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71050.087 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 308 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71050.736 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 307 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71050.732 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 306 | system user |                 | NULL | Connect |   71 | Waiting for work from SQL thread                                 | NULL                                          |  71052.083 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 305 | system user |                 | NULL | Connect |   71 | Waiting for prior transaction to start commit before starting ne | NULL                                          |  71052.747 |     0 |         0 |    0.000 |       52416 |             0 |        0 |
 
| 301 | system user |                 | NULL | Connect |   85 | Waiting for master to send event                                 | NULL                                          |  85050.574 |     0 |         0 |    0.000 |       40192 |             0 |        0 |
 
| 183 | root        | localhost:48711 | test | Query   |    0 | Filling schema table                                             | select * from information_schema. processlist |      0.820 |     0 |         0 |    0.000 |       84752 |             0 |     3134 |
 
+-----+-------------+-----------------+------+---------+------+------------------------------------------------------------------+-----------------------------------------------+------------+-------+-----------+----------+-------------+---------------+----------+
 
23 rows in set (0.01 sec)

Happens often while replicating.

10.1 commit 539b3ca87d97d15fcf1076ce1e4a83d5b00d9c26

 Comments   
Comment by Darshit Gavhane [ 2017-02-06 ]

Hello,
We recently upgraded from 10.0.20 to 10.1.18. We have 4 parallel slave threads running in default mode (conservative). After the upgrade we have started seeing the above mentioned issue where "show processlist;" shows "Write_rows_log_event::write_row(-1)". and replication seems to be hung and takes long time.

Comment by Elena Stepanova [ 2017-02-07 ]

dgavhane,

So, does it actually hang, or does it just take long time?
What happens if you keep the "parallel" replication configuration, but set the number of parallel threads to 1 – does the problem disappear?

Also, there was a couple of parallel replication performance improvements in 10.1.19, maybe they could help
https://github.com/MariaDB/server/commit/5dc7ad8
https://github.com/MariaDB/server/commit/50f19ca

Comment by Darshit Gavhane [ 2017-02-09 ]

Hello Elena Stepanova,

Thank you for your suggestions. We are now trying with one thread, haven't seen the issue reappear yet. Also, it takes really long time if we get into that situation. We tried stopping slave and restarting it, even that takes forever. I would as much like to prevent this issue from happening.

Thanks for pointing us to performance improvements in 10.1.19.

Thanks,
Darshit

Comment by Darshit Gavhane [ 2017-02-17 ]

Hello,

I wanted to mention one more issue that we are seeing on 10.1.18. During replication, slave processlist shows "186 | system user | | NULL | Connect | 0 | Unlocking tables | NULL | 0.000" and slave lag keeps on increasing. Although, it catches up eventually but takes too long.

Thanks,
Darshit

Comment by Antonio Fernandes [ 2018-02-03 ]

+1 but with 10.2.12

Comment by Elena Stepanova [ 2022-09-26 ]

10.1/10.2 are EOL, no information on newer versions.

Generated at Thu Feb 08 07:24:41 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.