Pixelmon Servers + Async + Entity Tracker = no bueno? ☹

Plugins Plugin Development
1

So I make this plugin over here

My users keep complaining about an error like this

[10:03:55] [pool-2-thread-1/INFO] [nucleus]: Server ran the command: /give TinyInJapan pixelmon:red_card 1 0 {ench:[{id:32,lvl:255}],display:{Name:"Burnt Magikarp Ticke
t",Lore:["Give this to an", "admin to exchange."]}}
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]: java.lang.Exception: Stack trace
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at java.lang.Thread.dumpStack(Thread.java:1333)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.entity.EntityTracker.handler$onAddEntityToTracker$zcp000(EntityTracker.
java:76)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.entity.EntityTracker.func_72785_a(EntityTracker.java)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.entity.EntityTracker.func_72786_a(EntityTracker.java:139)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.ServerWorldEventHandler.func_72703_a(ServerWorldEventHandler.java
:33)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.World.func_72923_a(World.java:1142)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.WorldServer.func_72923_a(WorldServer.java:1118)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.WorldServer.onSpongeEntityAdded(WorldServer.java:1403)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.WorldServer.forceSpawnEntity(WorldServer.java:1449)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.WorldServer.forceSpawnEntity(WorldServer.java:1432)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.event.tracking.phase.TrackingPhase.spawnEntityOrCapture(Trac
kingPhase.java:284)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.event.tracking.phase.general.GeneralPhase.spawnEntityOrCaptu
re(GeneralPhase.java:357)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.event.tracking.CauseTracker.spawnEntity(CauseTracker.java:55
8)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.world.WorldServer.func_72838_d(WorldServer.java:1174)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.entity.EntityUtil.dropItemAndGetStack(EntityUtil.java:1115)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.entity.EntityUtil.playerDropItem(EntityUtil.java:1075)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.entity.player.EntityPlayer.func_146097_a(EntityPlayer.java:380)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.entity.player.EntityPlayer.func_71019_a(EntityPlayer.java:321)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.command.CommandGive.func_184881_a(SourceFile:75)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at net.minecraft.command.CommandHandler.func_175786_a(CommandHandler.java:104)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.command.MinecraftCommandWrapper.tryExecute(MinecraftCommandWrapper.java:143)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.common.command.MinecraftCommandWrapper.process(MinecraftCommandWrapper.java:129)
[10:03:55] [pool-2-thread-1/INFO] [STDERR]: [java.lang.Thread:dumpStack:1333]:  at org.spongepowered.api.command.dispatcher.SimpleDispatcher.process(SimpleDispatcher.java:333)

Now the interesting thing is that it only happens with Pixelmon servers. The first time this problem was brought to light a user complained to blood about it, I talked to blood and showed him my source, he looked at it then went to nuVotifier and said the problem was there because nuVotifier is running async. I tried creating a work around by passing off the data into a thread safe queue and then running a task using the scheduler(from what I thought was the main thread) to run the commands in the queue, every so often (~half a second). No dice. From the looks of it there were improvements but not enough to warrant it “Fixed Status”.

Any help would be appreciated. I have a lot of anxious users waiting for a long awaited fix :frowning:

1 Like
2

That error is cut off - but from what I can see, it appears that a command is being run by a plugin off of the main thread.

Can you post the entire stacktrace, including a few lines directly below it?

3

Hey, yeah sure let me see if I can get a full error, one sec.

4

I was able to find this one, it’s more complete it seems.

5

NuVotifier fires VotifierEvent from an async task. When your listener recieves the async event, you directly call executeCommand, which causes all of the command code to run off the main thread.

In general, anything besides sending messages to players should occur on the main thread, as you can’t guarnatee how arbitrary commands may behave when not on the main thread.

6

How would you suggest me firing them from them from the main thread. I tried passing off into a threads safe queue that was instantiated in the main game thread but it didn’t work.

7

The way in which the queued commands are stored doesn’t really matter - it’s only every going to be accessed by one thread. The issue is this call to CommandManager#process, which occurs on the NuVotifier-created async task.

The simplest solution would be to spawn a new synchronous task for every vote event, which would be responsible for calling CommandManager#process. Alternatively, you could create a single, long-running synchronous task, which would periodically poll a thread-safe queue for new commands to run.

8

I attempted doing this… well the long running synchronous(?) task

 Scheduler scheduler = Sponge.getScheduler();
        Task.Builder taskBuilder = scheduler.createTaskBuilder();
        Task task = taskBuilder.execute(() -> giveReward())
                .delay(1000, TimeUnit.MILLISECONDS)
                .name("SeriousVote-CommandRewardExecutor")
                .submit(plugin);

But I’m not sure if this is the correct way to do it.

It was running, but people were still experiencing the error.

9

That’s the correct way of doing it. However, there are some issues with the rest of that class, from what I can see on Github:

  • You’re using a plain LinkedList, which is not safe. You should make use of Collections.synchronizedList, or use a collection class with synchronization built-in
  • Nothing actually ever gets added to executingQueue. Your vote listener runs the command directly, instead of adding it to the list.
10

Yeah currently the github shows the altered code to revert the changes. I will attempt making sure it is thread safe.
If i wanted to just spawn a new call
would it be

        Task.Builder taskBuilder = scheduler.createTaskBuilder();
        Task task = taskBuilder.execute(() -> giveReward())
                .name("SeriousVote-CommandRewardExecutor")
                .submit(plugin);

Adding this every time a vote is cast? Rather every time commands are to be executed.

11

Yes, that would work fine, assuming that the vote listener doesn’t modify any non thread-safe stuff that’s used by giveReward. Using a long-running task would be more efficient, but it’s not strictly necessary.

12

Cool beans, thanks alot for your help Aaron :slight_smile:
I’ll implement the changes and mark it as resolved if it’s resolved.
Otherwise you’ll hear from me soon :stuck_out_tongue:

13

So I keep running into problems with the scheduler not running. It just never starts. I’ve tried starting it just about everywhere, I’m stumped.think you could help me out?

https://github.com/curscascis/SeriousVote/blob/bleeding/src/main/java/net/adamsanchez/seriousvote/SeriousVote.java#L217-L225

Also in my current working build I have it as a class, and it never runs. No errors or anything :frowning:

I tried my best to follow the guidelines here:
https://docs.spongepowered.org/master/en/plugin/scheduler.html

14

I’m almost certain that you meant to use interval, not delay - since this task is supposed to run repeatedly.

15

After making the change I’m almost certain your certainty is correct. #needMoreSleep