Random chunk updates don't occur in a world made in 1.18.0

[Wesmania]

Game Version

v1.18.1

Platform

Linux

Modded

None

SP/MP

Multiplayer

Description

We created our server world in 1.18.0, and after moving it to 1.18.1 we noticed that grass stopped spreading to dirt blocks. Manually ticking the blocks using /tickblock cause grass to spread fine, so I assume it's because for some reason we no longer have random block updates. There are also issues with lake ice and snow under other blocks not melting, which would confirm that theory.

For all I can tell, server and world settings we know of that affect random block updates are all set to defaults.

How to reproduce

No idea. We can tar and share our data directory, though at this point it's around 20 GiB.

Screenshots

No response

Logs

Logs from recent server run

[radfast]

I cannot reproduce this in a new 1.18.2-rcX world. I can see no mechanism why a world created in 1.18.0 would not tick grass blocks when loaded in a 1.18.2 game: a grass block is a grass block, and a soil block is a soil block, whether created by 1.18.0 worldgen or 1.18.2 worldgen.

Are there any other issues:

• anything seen in server-main.txt log?
• does the game calendar progress normally, with the seasons, crops growing, fruit trees changing, food spoiling, etc?
• can you place a dirt block and watch it for 24 in-game hours? that should normally be enough time for it to become covered with sparse grass if it has normal grassy neighbours. Use /time speed 6000 to make the calendar progress way faster than normal, like fast-forwarding, then /time speed 60 to bring it back to normal

[Wesmania]

The game calendar progresses normally. Crops grow, food spoils, all that. I haven't seen anything unusual in logs either. I'll see about doing the test you mentioned, though we had multiple players stick around the same area with big dirt patches next to grass, and no grass grew whatsoever.

I imagine it might be that some obscure configuration option is set that's preventing random block updates on our server, but I checked what I could on the wiki and found no evidence to that.

[Wesmania]

Is output of /debug tickhandlers relevant here?

GameTickListenersBlock=0, GameTickListenersEntity=7574, DelayedCallbacksBlock=0, DelayedCallbacksEntity=425, SingleDelayedCallbacksBlock=0 @ 0

[radfast]

No, it's not that type of ticking. Grass ticking is "random block ticking", if you are looking at the API the code for it is Block.ShouldReceiveGameTicks() and Block.OnServerGameTick().

Crop death, lake ice melting, water and lava flow, leaf-block decay, cut vine decay, and soil grass spreading (or dying) all use the same system. Also snow melting within an individual chunk if the chunk stays loaded into spring.

I can't think of any reason why these systems would not be working in 1.18.2-rcX - even in a world created in 1.18.0. These things all look to be working OK in my tests, but I will keep an open mind. The best way to test quickly is to speed up time like I wrote, you should be able to see these things changing in front of your eyes.

[Wesmania]

I did some more testing. Waiting multiple ingame days did not cause the dirt block to regrow grass. On the other hand, after removing just the save file (.vcdbs) grass grows fine - same test on the recreated save had the block regrow grass.

I'd love to send the data file we have for testing, but at this point it's 7 gigabytes compressed. Is there some server command that would remove all chunks except those directly around the player? If not, then I guess I could give you access to the machine we're running the server on to download the data. I'm not much of a sysadmin, so I don't know what the best method would be, maybe you post an ssh public key and I let you in via SSH as a guest user?

[a-cim]

Hey all, joining this conversation because my server is having this same issue, and we also started from a 1.18.0 world. I can provide more details about the world and server config upon request.

@Wesmania, I do have a question. You mentioned removing the save file:

On the other hand, after removing just the save file (.vcdbs) grass grows fine - same test on the recreated save had the block regrow grass.

Would you be able to elaborate further on this solution? When removing the save file, does this mean you generated a new world on that same server?

[Wesmania]

Yes, all I did was remove the .vcdbs file, that generated a new world.

[radfast]

You could maybe try to export as a schematic, a 32 x 32 area of soil & grass from an affected chunk - then anyone can import that schematic and see if the same behavior happen. Commands /we mex [filename] to export to the WorldEdit folder on the server, or /we mexc [filename] to export and download to the player's own PC, the WorldEdit folder (it might ask you for extra confirmation of permissions to receive a file from the server).

Another question - if you teleport to a totally new area of the broken map, does grass behave normally there, or is the grass still not spreading even in a previously untouched region?

Final question (for now), did the standard remapping process ("This save game was created with an older version of the game, to restore some of the blocks a remapping and world reload is required") proceed normally when you first updated game versions?

[Wesmania]

Teleporting to a new area also exhibits the same behaviour. I get the feeling it's something with the world configuration rather than the block data itself. I'm attaching a schematic from that world either way, just in case. If you want, I can give you access to our world file via sftp or something. I don't know the answer to the last question, I didn't pay attention to that. brokengrass.json.gz

[a-cim]

Final question (for now), did the standard remapping process ("This save game was created with an older version of the game, to restore some of the blocks a remapping and world reload is required") proceed normally when you first updated game versions?

Fairly certain we did not run this process for our server. 💩

Is /fixmapping applyall the right command to run this process, and would there be any implications to running this on a populated multiplayer server?

[Wesmania]

On my server /fixmapping applyall says there are no applicable remappings.

[a-cim]

Went ahead and tried running /fixmapping applyall, as well, and got the same 'no applicable remappings' response.

[tyronx]

I added more debug commands for this in 1.18.4+

Please run /debug bt qi and show me the output. My suspicion is that perhaps the tick queue gets gigantic the /tickblock command has been moved to /debug bt at

[a-cim]

Woo, thank you for the fun, new tools! Here's the output from repeated tests of /debug bt qi around the same area.

[tyronx]

wow okay, not overfilled in that case. thanks.

[Wesmania]

I can confirm the same thing on my end. The number of items in the queue fluctuates at around 0-10.

[Wesmania]

Wouldn't it be easier if you downloaded one of our saves to test it on your end? Ours is pretty big, but I have sftp set up so it can be downloaded, I just need an SSH public key.

[tyronx]

yea ok, lets try that. Whats your name on discord? I'd DM you my pub key

[Wesmania]

mazornoob

[Wesmania]

Or I guess "mazornoob#1502", discord is stupid like this.

[Wesmania]

I don't think I got any DM, did I post the right username?

[a-cim]

@Wesmania - I tried adding you on Discord to ask some questions around this bug, but I'm unable to send you a friend request due to your account's privacy settings. Tyron might be having the same issue reaching out to you. For your reference, this is the error message I get,

[Wesmania]

Huh, okay. I didn't know that was necessary to send private messages. I flipped a switch, it should be possible now.

[Wesmania]

@tyronx I was contacted by a-cim on DM, so DMs should work now.

[Wesmania]

Any chance this can be pushed forward?

[Wesmania]

I decided to try and check things myself via Harmony modding on server version 1.18.5, and so far I found something very strange. I hooked up to the tryTickBlock method, like this:

using Vintagestory.API.Server;
using Vintagestory.API.Common;
using Vintagestory.GameContent;

using HarmonyLib;

[assembly: ModInfo("Test mod")]

class Core : ModSystem
{
    public static ICoreServerAPI _api;
    public override void StartServerSide(ICoreServerAPI api)
    {
        _api = api;
        base.StartServerSide(api);
    Patcher.Patch();
    }
}

class Patcher
{
    public static void Patch() {
        var harmony = new Harmony("com.foobar.patch");
        harmony.PatchAll();
    }
}

[HarmonyPatch(typeof(Vintagestory.Server.ServerSystemBlockSimulation))]
[HarmonyPatch("tryTickBlock")]
class Patch {
    static bool Prefix(Vintagestory.API.Common.Block block, Vintagestory.API.MathTools.BlockPos atPos) {
    Core._api.World.Logger.Event("Modded tryTickBlock at " + atPos.ToLocalPosition(Core._api).ToString());
        return true;
    }
}

I wanted to compare the local position to spawn-relative coordinates of the dirt block I wanted to check, but decided to see first if the game prints something out on its own. I got thousands of lines like this in logs:

11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5610,Y=-2944,Z=-15816
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5609,Y=-2913,Z=-15816
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5613,Y=-2922,Z=-15817
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5624,Y=-2937,Z=-15791
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5620,Y=-2930,Z=-15797
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5616,Y=-2941,Z=-15805
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5627,Y=-2936,Z=-15808
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5631,Y=-2917,Z=-15791
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5612,Y=-2940,Z=-15800
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5613,Y=-2937,Z=-15792
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5613,Y=-2942,Z=-15790
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5620,Y=-3616,Z=-15945
11.6.2023 20:59:58 [Event] Modded tryTickBlock at X=5610,Y=-3612,Z=-15813

The X and Z coordinates match spawn-relative coordinates of where I'm running tests, but the Y coordinate is some absurd negative value. Maybe this is why blocks fail to tick? Somewhere the Y coordinate is calculated incorrectly or the origin is set incorrectly in the save file, and every single block tick attempts fails since there's no such coordinate? To complete the picture, here are sample results of printing just BlockPos, without calling ToLocalPosition:

11.6.2023 21:09:05 [Event] Modded tryTickBlock at 1029618, -2943, 1008200
11.6.2023 21:09:05 [Event] Modded tryTickBlock at 1029625, -2931, 1008210
11.6.2023 21:09:05 [Event] Modded tryTickBlock at 1029616, -3608, 1008065
11.6.2023 21:09:05 [Event] Modded tryTickBlock at 1029618, -3612, 1008065
11.6.2023 21:09:05 [Event] Modded tryTickBlock at 1029614, -3601, 1008067

One more interesting thing: the Y values for BlockPos are all grouped up within small intervals with a distance of about 650 between each two: -300ish, -950ish, -1600ish, -2250ish, -2900ish and -3600ish.

Any tips on what else I could hook to to test further?

[Wesmania]

I investigated the coordinates I got. Assuming that blocks above the highest non-air block in chunks is never ticked and that correct Y values go from 0 to 255, I reconstructed the formula for "buggy" Y values:

Y_{bug} = -1 - 288 - (Y % 32)  - (32 * 19) * floor(Y / 32)

[Wesmania]

And I can confirm that the manual tickBlock command uses a regular, positive Y value, in case of a block I tested it's 113.

[Wesmania]

With some more work I wrote a mod that fixes the issue, that is running /time scale 6000 with the mod loaded causes blocks to quickly become grassy again. Posting it below for reference. Am I using GetBlockAccessor correctly?

using Vintagestory.API.Server;
using Vintagestory.API.Common;
using Vintagestory.GameContent;

using HarmonyLib;

[assembly: ModInfo("Grass fix")]

class Core : ModSystem
{
    public static ICoreServerAPI _api;
    public override void StartServerSide(ICoreServerAPI api)
    {
        _api = api;
        base.StartServerSide(api);
    Patcher.Patch();
    }
}

class Patcher
{
    public static void Patch() {
        var harmony = new Harmony("org.4channel.vspatch");
        harmony.PatchAll();
    }
}

[HarmonyPatch(typeof(Vintagestory.Server.ServerSystemBlockSimulation))]
[HarmonyPatch("tryTickBlock")]
class GrassFix {
    static int FixY(int y_bug) {
    var y_mod_32 = (-y_bug - 289) % 32;
    var floor_y_div_32 = ((-y_bug - 289) - (y_mod_32)) / 608;
    return floor_y_div_32 * 32 + y_mod_32;
    }

    static bool Prefix(out int __state, ref Vintagestory.API.Common.Block block, Vintagestory.API.MathTools.BlockPos atPos) {
    if (atPos.Y < 0) {
        __state = atPos.Y;
        atPos.Y = GrassFix.FixY(atPos.Y);
        block = Core._api.World.GetBlockAccessor(true, false, false).GetBlock(atPos);
    } else {
        __state = 0;
    }
        return true;
    }

    static void Postfix(int __state, Vintagestory.API.Common.Block block, Vintagestory.API.MathTools.BlockPos atPos) {
    if (__state != 0) {
        atPos.Y = __state;
    }
    }
}

[Wesmania]

@a-cim pointed out that the formula I posted doesn't quite match with the lower numbers, so I took a look at them again. The relation is actually non-linear, I guess it might be an artifact of working with fractions? I'm posting updated python code for the correct Y_{bug} and the reverse.

block_distances = [-640, -672, -640, -672, -672, -640, -672]
block_offsets = [0, 0, 0, 0, 0, 0, 0, 0]
block_offsets[0] = -289
for i in range(0, 7):
    block_offsets[i + 1] = block_offsets[i] + block_distances[i]

def y_bug(y):
    return block_offsets[y // 32] - (y % 32)

def y(y_bug):
    i = 0
    while i < 7:
        if y_bug <= block_offsets[i] and y_bug > block_offsets[i + 1]:
            break
        i += 1
    offset = block_offsets[i]
    return i * 32 + ((offset - y_bug) % 32)

This matches all 256 Y values that I logged.

[Wesmania]

And a corresponding updated mod fix:

using Vintagestory.API.Server;
using Vintagestory.API.Common;
using Vintagestory.GameContent;

using HarmonyLib;

[assembly: ModInfo("Grass Janny Posting: Repentance", Side = "Server")]

class Core : ModSystem
{
    static int[] block_distances = new int[] {-640, -672, -640, -672, -672, -640, -672};
    static int[] block_offsets = new int[8];

    public static ICoreServerAPI _api;
    public override void StartServerSide(ICoreServerAPI api)
    {
    block_offsets[0] = -289;
    for (int i = 0; i < 7; i++) {
        block_offsets[i + 1] = block_offsets[i] + block_distances[i];
    }
        _api = api;
        base.StartServerSide(api);
    Patcher.Patch();
    }

    public static int y(int y_bug) {
    int i = 0;
    while (i < 7) {
        if (y_bug <= block_offsets[i] && y_bug > block_offsets[i + 1]) {
        break;
        }
        i += 1;
    }
    int offset = block_offsets[i];
    return i * 32 + ((offset - y_bug) % 32);
    }
}

class Patcher
{
    public static void Patch() {
        var harmony = new Harmony("org.4channel.vspatch");
        harmony.PatchAll();
    }
}

[HarmonyPatch(typeof(Vintagestory.Server.ServerSystemBlockSimulation))]
[HarmonyPatch("tryTickBlock")]
class GrassJannyService {
    static bool Prefix(out int __state, ref Vintagestory.API.Common.Block block, Vintagestory.API.MathTools.BlockPos atPos) {
    if (atPos.Y < 0) {
        __state = atPos.Y;
        atPos.Y = Core.y(atPos.Y);
        block = Core._api.World.GetBlockAccessor(true, false, false).GetBlock(atPos);
    } else {
        __state = 0;
    }
        return true;
    }

    static void Postfix(int __state, Vintagestory.API.Common.Block block, Vintagestory.API.MathTools.BlockPos atPos) {
    if (__state != 0) {
        atPos.Y = __state;
    }
    }
}

[tyronx]

hey, can you please initiate the DM to me and send me the savegame please?

[jonnypotseed]

Have any new developments with this issue been made? The public server Glitchendor is still suffering from it.

[tyronx]

hi sorry, I lost track of it, under which discord name did you send me the savegame? [Edit:] nvm, i found the DM

[tyronx]

Alright, i got it. Its due to the fact that your world is 2x2mil world size. It caused an integer overflow. Should be fixed next release. Sorry for the long wait.

If you are curious the bug is in BlockSimulation.cs, method tickChunk():

            basePos.Set(
                chunksize * (int)(index3d % server.WorldMap.ChunkMapSizeX),
                chunksize * (int)(index3d / (server.WorldMap.ChunkMapSizeX * server.WorldMap.ChunkMapSizeZ)),
                chunksize * (int)((index3d / server.WorldMap.ChunkMapSizeX) % server.WorldMap.ChunkMapSizeZ)
            );

server.WorldMap.ChunkMapSizeX * server.WorldMap.ChunkMapSizeZ is larger than the int max value, causing an overflow. The fix is to prefix it with a (long) typecast so the multiplication is made in longs not ints.