Solved ChunkLoadEvent called before entities load.

Discussion in 'Spigot Plugin Development' started by BanePig, Jul 18, 2021.

  1. I'm posting this as "solved" because I did find a "solution," but its a messy one and I want to post here just in case there is a better solution, someone else has a similar problem, or this is a bug.

    I'm making a plugin where I want to track the location of a set of items. When the server shuts down, I save the location of these items. When the server turns on, I load the chunk at each location. My hope is that after loading the chunk I will get a ChunkLoadEvent and I can look through entities in that chunk to see if any of them is an item I'm interested in. I noticed that this pretty much never works, because whenever I loaded a chunk there were never any entities in the chunk. Still, I knew there should have been an item in the chunk because I could log on the server and find the item myself.

    I tried delaying the search by a tick, but this still wasnt enough. So, for testing, I created a test plugin with this class:

    Code (Java):
    public class Main extends JavaPlugin implements Listener {
        public Main() {
            super();
        }

        @Override
        public void onEnable() {
            getLogger().info("Enabled.");
            getServer().getPluginManager().registerEvents(this, this);
        }

        @Override
        public void onDisable() {
            getLogger().info("Disabled.");
        }

        @EventHandler
        public void onChunkLoad(ChunkLoadEvent ev) {
            // Cry about it
            final int[] tickOff = {0};
            final int[] id = {0};

            if(ev.getChunk().getEntities().length != 0) {
                getLogger().info("First entity loaded after " + tickOff[0] + " ticks.");
                return;
            }
            id[0] = getServer().getScheduler().scheduleSyncRepeatingTask(this, () -> {
                tickOff[0]++;
                if(ev.getChunk().getEntities().length != 0) {
                    EntityType type = ev.getChunk().getEntities()[0].getType();
                    getLogger().info("First entity (type=" + type + ") loaded after " + tickOff[0] + " ticks.");
                    getServer().getScheduler().cancelTask(id[0]);
                }
            }, 1, 1);
        }
    }
    Most entities seem to load about 2-3 ticks after the event is called. With some loading about 10 ticks after. I found that I could kinda get around this by just delaying 20 ticks, which was usually enough, but it's sort of unsafe and theres always a risk of something changing in that second.

    I'll also post the full output (Note some of the entities could just be walking into the chunk after a bit, so the really long waits is probably just that).

    Code (Text):
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=PLAYER) loaded after 1 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 13 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 11 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 10 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 10 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 8 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 6 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 14 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 12 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 5 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 5 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SQUID) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=VILLAGER) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ENDERMAN) loaded after 5 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 5 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=GLOW_SQUID) loaded after 5 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=GLOW_SQUID) loaded after 4 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 3 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 3 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 12 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 5 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 3 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 3 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=FOX) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=SPIDER) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 2 ticks.
    [18:48:54] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 10 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 5 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SPIDER) loaded after 23 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SPIDER) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=ENDERMAN) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=MINECART_CHEST) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=ENDERMAN) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 21 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=RABBIT) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=ZOMBIE) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SQUID) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SQUID) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CREEPER) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=MINECART_CHEST) loaded after 3 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=ENDERMAN) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SKELETON) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SPIDER) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 4 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=MINECART_CHEST) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=MINECART_CHEST) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=WOLF) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 2 ticks.
    [18:48:55] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=DROPPED_ITEM) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=WOLF) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:56] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 12 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 12 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 8 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=MINECART_CHEST) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=COW) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=PIG) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=GOAT) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=LLAMA) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=SHEEP) loaded after 2 ticks.
    [18:48:57] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 69 ticks.
    [18:48:59] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 89 ticks.
    [18:49:00] [Server thread/INFO]: [TestPlugin] First entity (type=BAT) loaded after 115 ticks.
    [18:49:00] [Server thread/INFO]: [TestPlugin] First entity (type=CHICKEN) loaded after 116 ticks.