Ticket 5400

I'm wondering if the pending queries requested a very large amount of data and are bogging the database down. Killing those has solved the problem for others.

In 17.11, we added a MaxQueryTimeRange parameter to slurmdbd.conf, so administrators can limit the time range of a query. That may be of interest to you whenever you upgrade.

Since your restart of the slurmdbd and database, have you seen this problem occur again?

It's been coming up pretty regularly. Always seems to be late in the afternoon. I'll dig around and see if some user has something abusive in a crontab or something. Is there a good way to get more information about where the pending queries are coming from? I guess a number of them are referencing quartz's tables.

(In reply to Ryan Day from comment #4)
> It's been coming up pretty regularly. Always seems to be late in the
> afternoon. I'll dig around and see if some user has something abusive in a
> crontab or something. Is there a good way to get more information about
> where the pending queries are coming from? I guess a number of them are
> referencing quartz's tables.

You can use

sacctmgr show transaction

(documented in the man page). It doesn't show exactly what the query was, but it shows what it was doing, where it came from, who issued it, when it was issued, and some extra information.

You can limit the time period you want to see with "start=" and "end=". You can also specify the format, which is useful if you want to expand a field (such as info) where the width isn't enough to show all the information.

sacctmgr show transaction start=7/1/18 end=7/12/18 format=time,action,actor,where,info%100

Have you been able to identify the offending queries? Are you still seeing this come up?


17.11.8 is due to be released this week. 18.08 is due to be released next month. When that happens, 17.02 will no longer be supported, so we encourage you to make a plan to upgrade soon. Both versions have the MaxQueryTimeRange parameter for slurmdbd.conf, which should help with this issue. If you're mainly concerned about stability, I'd encourage you to upgrade to 17.11.

Unfortunately, I haven't caught this in the act since filing the bug. I do have 17.11 running in our test environment and plan to get it out in production around when you release 18.08.

In that case, I'm going to close this as resolved/infogiven for now. If you have problems again, feel free to re-open the ticket.

I'm re-opening this as I'm now able to reproduce it on 17.02.10 and 17.11.8

Our accounts staff (the folks who add / remove users from accounts, etc) tend to start sacctmgr sessions and leave them running. It appears that, under certain conditions, the mariadb is not releasing table metadata locks until the sacctmgr session is exited. E.g. I start two sacctmgr sessions. In the first, I add an account and then show a user:

sacctmgr: add account guests parent=overhead cl=opal
 Associations
  A = guests     C = opal      
 Settings
  Parent        = overhead
Would you like to commit changes? (You have 30 seconds to decide)
(N/y): y
sacctmgr: show user day36 witha
      User   Def Acct     Admin    Cluster    Account  Partition     Share MaxJobs MaxNodes  MaxCPUs MaxSubmit     MaxWall  MaxCPUMins                  QOS   Def QOS 
---------- ---------- --------- ---------- ---------- ---------- --------- ------- -------- -------- --------- ----------- ----------- -------------------- --------- 
     day36         lc Administ+      borax         lc                    1                               10000                               normal,standby           
     day36         lc Administ+   catalyst         lc                    1                               10000                         expedite,normal,sta+           
     day36         lc Administ+      flash         lc                    1                               10000                               normal,standby           
     day36         lc Administ+       opal         lc                    1                                                                   normal,standby           
     day36         lc Administ+     pascal         lc                    1                               10000                               normal,standby           
     day36         lc Administ+     quartz         lc                    1                               10000                         expedite,normal,sta+           
sacctmgr:

In the second session, I add a user to that account, which works fine, then delete a user from that account, which hangs:

[day36@opal185:~]$ sacctmgr
sacctmgr: add user day36 account=guests cl=opal
 Associations =
  U = day36     A = guests     C = opal      
 Non Default Settings
Would you like to commit changes? (You have 30 seconds to decide)
(N/y): y
sacctmgr: delete user day36 account=guests cl=opal
 Deleting user associations...
  C = opal       A = guests     U = day36    
Would you like to commit changes? (You have 30 seconds to decide)
(N/y): y
<hangs>

Looking at the db, the sacctmgr process that is running the delete (23626) is 'waiting for table metadata lock':
[root@elsie2:~]# mysqladmin proc stat
+-------+-------+-----------+---------------+---------+------+---------------------------------+-------------------------------------------------+----------+
| Id    | User  | Host      | db            | Command | Time | State                           | Info                                            | Progress |
+-------+-------+-----------+---------------+---------+------+---------------------------------+-------------------------------------------------+----------+
| 19    | slurm | localhost | slurm_acct_db | Sleep   | 159  |                                 |                                                 | 0.000    |
| 14243 | slurm | localhost | slurm_acct_db | Sleep   | 0    |                                 |                                                 | 0.000    |
| 23624 | slurm | localhost | slurm_acct_db | Sleep   | 39   |                                 |                                                 | 0.000    |
| 23626 | slurm | localhost | slurm_acct_db | Query   | 8    | Waiting for table metadata lock | alter table "opal_assoc_table" AUTO_INCREMENT=0 | 0.000    |
| 23635 | root  | localhost |               | Query   | 0    |                                 | show processlist                                | 0.000    |
+-------+-------+-----------+---------------+---------+------+---------------------------------+-------------------------------------------------+----------+
Uptime: 1740759  Threads: 5  Questions: 2100929  Slow queries: 6  Opens: 203  Flush tables: 2  Open tables: 164  Queries per second avg: 1.206
[root@elsie2:~]#

The delete in the second sacctmgr session completes as soon as I exit the first sacctmgr session, which leads me to believe that the lock is not released until the sacctmgr exits. Is this expected behavior? The accounts specialists say that they've used sacctmgr this way for a long time, and it never used to lead to problems.

Thanks for the detailed instructions. I was able to reproduce it just like you described on both Debian and CentOS. I'll look into this further. I'm not sure if it's expected behavior or not, but my gut says it's not.

This is definitely a bug. But it doesn't exist on the 18.08 branch (18.08 will be released by the end of the month). I haven't yet identified which commit fixes it.

I also have found that reproducing it is as simple as this:

- have 2 sacctmgr interactive sessions open
- in one
  * show users
- in the other
  * add user account=<accountname>
  * del user account=<accountname>

So I think it's something wrong with show users. Since it has already been fixed, I'm just trying to identify the commit that fixed it.

This commit solves the problem.

https://github.com/schedmd/slurm/commit/4a16541bf0e

My guess is that sacctmgr show users is holding metadata locks that prevent AUTO_INCREMENT from being changed, and prior to that commit, deleting a user would reset AUTO_INCREMENT to 0 for the association table, but it can't delete the user because of show users. This commit fixes that issue.

We only put this into 18.08 because it's a change in behavior that we didn't want to introduce to 17.11, but you should be fine to apply this directly to 17.11 if you want.

Does this solution work for you?

That sounds good. I'll apply it to 17.11 and get it onto our test system to make sure it works for us. You can probably close this though and I'll re-open if I run into more problems.

(In reply to Marshall Garey from comment #15)
> This commit solves the problem.
> 
> https://github.com/schedmd/slurm/commit/4a16541bf0e
> 
> My guess is that sacctmgr show users is holding metadata locks that prevent
> AUTO_INCREMENT from being changed, and prior to that commit, deleting a user
> would reset AUTO_INCREMENT to 0 for the association table, but it can't
> delete the user because of show users. This commit fixes that issue.
> 
> We only put this into 18.08 because it's a change in behavior that we didn't
> want to introduce to 17.11, but you should be fine to apply this directly to
> 17.11 if you want.
> 
> Does this solution work for you?

Okay. Closing as resolved/fixed in 18.08

https://github.com/schedmd/slurm/commit/4a16541bf0e