LuckPerms

LuckPerms

41.4k Downloads

Error "Another command is being executed, waiting for it to finish..."

Feldmarschall opened this issue · 16 comments

commented

Description

Short report, as there is almost no support on Discord. Since the last LuckPerm update, my console commands no longer work.

Serverversion:

This server is running Paper version git-Paper-562 (MC: 1.16.5) (Implementing API version 1.16.5-R0.1-SNAPSHOT)
You are running the latest version
Previous version: git-Paper-526 (MC: 1.16.5)

LuckPerm version 5.3.0

Commands:

     - '[console] lp user %player_name% permission set test.test1'
      - '[console] lp user %player_name% permission set test.test2'
      - '[console] lp user %player_name% permission set test.test3 false'
      - '[console] lp user %player_name% permission unset test.test4 false'
      - '[console] lp user %player_name% permission unset test.test5 false'

(DeluxeMenu)

Log:

https://pastebin.com/TswLeLxF

commented

The logs just indicate that your server is struggling to keep up with LuckPerms command executions (they happen one after the other in the order in which they were executed)

I assume the commands do eventually go through?

Are you able to reliably reproduce the problem?

commented

The problem is that no player can join the server when the problem occurs.
I always have to restart the server. The following commands (luckPerm changes) are not saved.

Yes, whenever my player group changes their race. Then many permissions are changed.

As far as I know, this happens with the latest 3.5.0 version. I will patch back today or tomorrow.

commented

The problem is that no player can join the server when the problem occurs.

This would indicate that the problem is probably more significant than just LuckPerms.. the LP command queue getting stuck is one thing, but that wouldn't (shouldn't) prevent players from connecting to the server.

More likely you have a thread / CPU starvation problem which is resulting in the server not responding.

commented

What is your discord name?

commented

Sir William, the post was not long ago. 12:44 :)

But in this issure are more details.

commented

I don't know exactly. In any case, I patched the old version. Now everything works again. (LuckPerm 5.2.76)

The 20 commands are executed instantaneously without the server getting problems.

commented

Could you try using 5.3.11 - https://luckperms.net/download

Let me know if that is any better, I've added a patch that may improve the situation :)

commented

It doesn't work with the version either.

commented
[00:21:46 WARN]: [LuckPerms] Command execution [user, Adurien, permission, unset, adurath.volk.halblinge] has not completed. Trace: 
  [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
  [email protected]/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:885)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:917)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1240)
  [email protected]/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:267)
  me.lucko.luckperms.common.command.CommandManager.lambda$executeCommand$1(CommandManager.java:148)
  me.lucko.luckperms.common.command.CommandManager$$Lambda$8715/0x00000008421bb840.get(Unknown Source)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
  [email protected]/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
  [email protected]/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
  [email protected]/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
  [email protected]/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
  [email protected]/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
[00:21:46 WARN]: [LuckPerms] Command execution [user, Adurien, permission, unset, adurath.volk.nord] has not completed. Trace: 
  [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
  [email protected]/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:885)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:917)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1240)
  [email protected]/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:267)
  me.lucko.luckperms.common.command.CommandManager.lambda$executeCommand$1(CommandManager.java:148)
  me.lucko.luckperms.common.command.CommandManager$$Lambda$8715/0x00000008421bb840.get(Unknown Source)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
  [email protected]/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
  [email protected]/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
  [email protected]/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
  [email protected]/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
  [email protected]/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
[00:21:46 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:21:46 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:21:56 WARN]: [LuckPerms] Command execution [user, Adurien, permission, unset, adurath.volk.sturmmänner] has not completed. Trace: 
  [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
  [email protected]/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:885)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:917)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1240)
  [email protected]/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:267)
  me.lucko.luckperms.common.command.CommandManager.lambda$executeCommand$1(CommandManager.java:148)
  me.lucko.luckperms.common.command.CommandManager$$Lambda$8715/0x00000008421bb840.get(Unknown Source)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
  [email protected]/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
  [email protected]/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
  [email protected]/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
  [email protected]/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
  [email protected]/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
[00:21:56 WARN]: [LuckPerms] Command execution [user, Adurien, permission, unset, adurath.volk.aishuri] has not completed. Trace: 
  [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
  [email protected]/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:885)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:917)
  [email protected]/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1240)
  [email protected]/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:267)
  me.lucko.luckperms.common.command.CommandManager.lambda$executeCommand$1(CommandManager.java:148)
  me.lucko.luckperms.common.command.CommandManager$$Lambda$8715/0x00000008421bb840.get(Unknown Source)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
  [email protected]/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692)
  [email protected]/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
  [email protected]/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
  [email protected]/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656)
  [email protected]/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
  [email protected]/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
[00:21:56 INFO]: [LP] Another command is being executed, waiting for it to finish...
commented

Can you upload your full log?

commented

Ah ok, I think I see what the problem is.

Could you try again using v5.3.12 :)

commented

Now it works, but there is still an error.

https://pastebin.com/H7jsAmu4

commented

Alright, 3rd time lucky... please try with 5.3.14 :)

commented

Yes it works fine. Thanks. One more Question.

Is that still normal? In the past, this display did not come up, but immediately the output.

[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
[00:34:06 INFO]: [LP] Another command is being executed, waiting for it to finish...
commented

Yes - that's normal.

Great that the issue is fixed!

A closing comment from me: ask yourself, is it necessary to run so many commands at once? If you are assigning lots of permissions to a user, it would be better to add those permissions to a group, then just execute one command to add the group to the user.

For example, if you want to routinely give permissions:

essentials.ban
essentials.mute
essentials.fly

to a user.

Instead of running

/lp user {USER} permission set essentials.ban true
/lp user {USER} permission set essentials.mute true
/lp user {USER} permission set essentials.fly true

every time, add these permissions to a group:

/lp group mygroup permission set essentials.ban true
/lp group mygroup permission set essentials.mute true
/lp group mygroup permission set essentials.fly true

then just add the user to the group (one command each time instead of 3!)

/lp user {USER} parent add mygroup