Uploaded image for project: 'Minecraft: Java Edition'
  1. Minecraft: Java Edition
  2. MC-119971

Various duplications, deletions, and data corruption at chunk boundaries, caused by loading outdated chunks — includes duping and deletion of entities/mobs, items in hoppers, and blocks moved by pistons, among other problems

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Resolution: Fixed
    • Affects Version/s: Minecraft 1.12.1, Minecraft 1.12.2, Minecraft 1.13
    • Fix Version/s: Minecraft 18w30a
    • Labels:
      None
    • Confirmation Status:
      Unconfirmed

      Description

      In the process of testing the fix for MC-79154, I uncovered another potentially serious but unrelated Minecraft bug. I found it by looking at MCP for 1.11.2, although I'M SURE it affects 1.12.x also.

      Here's what I saw in my logs:

      // On tick 5034266, a chunk unload happens, causing a hopper I was monitoring to get serialized as NBT data and queued for I/O:
      
      Hopper save on tick 5034266 ser=29333 oser=7
        Position at co{x=-1, y=56, z=2}
          data: {TransferCooldown:3,x:-1,y:56,z:2,Items:[],id:"minecraft:hopper",serial_num:7L,Lock:""}
      
      // Two game ticks later, the same chunk is reloaded, but we get completely different data:
      
      Hopper load on tick 5034268 ser=29341 oser=7
        Position at co{x=-1, y=56, z=2}
          data: {TransferCooldown:7,x:-1,y:56,z:2,Items:[0:{Slot:0b,id:"minecraft:redstone",Count:1b,Damage:0s}],id:"minecraft:hopper",serial_num:7L,Lock:""}
      
      // Searching backwards in the log, we find that this is what was written out the previous time this chunk was unloaded:
      
      Hopper save on tick 5034170 ser=29323 oser=7
        Position at co{x=-1, y=56, z=2}
          data: {TransferCooldown:7,x:-1,y:56,z:2,Items:[0:{Slot:0b,id:"minecraft:redstone",Count:1b,Damage:0s}],id:"minecraft:hopper",serial_num:7L,Lock:""}
      

      (In case you're wondering why the saves are only 96 ticks apart, I think it's because the one on tick 5034170 happened when I logged out or restarted the server. I forget exactly, but it appears I triggered an off-schedule auto-save. This is actually relevant to Rich Crosby's fix for MC-22147. Briefly, I thought it might be moot, since auto-saves are 45 seconds apart. What are the chances that the I/O system would be backlogged by 45 seconds, triggering that bug? But anything that causes two auto-saves to occur close to each other CAN trigger that bug.)

      Anyhow, so, how could we be loading an old version of this data? Well, here's what I found:

      There is a time between when AnvilChunkLoader.writeNextIO dequeues a chunk from chunksToRemove and when the I/O write completes when AnvilChunkLoader.loadChunk could come along looking for the same chunk. If that happens, AnvilChunkLoader.loadChunk will load a stale version of the chunk.

      The key methods on RegionFile are synchronized, so I'm pretty sure it can't read corrupt data. Sector allocation and low-level file access are all synchronized. The problem is what happens in the period of time when CompressedStreamTools and the various NBTTag objects are are writing out the NBT data to the ChunkBuffer (derived from ByteArrayOutputStream), including the overhead of doing the compression.

      I don't have an "easy one-line" fix for this.

      Let's say that AnvilChunkLoader.writeNextIO were to pick a chunk out of the chunksToRemove but not actually remove it form that container during I/O. That would be great for the case when the same chunk is reloaded. But what if another save for the same chunk comes along during that time? Then the newer one would replace the older one in chunksToRemove while the older one is being saved, and then when the write was done, the newer one would get deleted from chunksToRemove.

      That condition could be eliminated (fixing Crosby's observation in the process) if an auto-save can't even be started if AnvilChunkLoader's I/O queue is not empty.


      How to reproduce: Point two hoppers into each other on a chunk border, throw one item in, create lag.

        Attachments

        1. 2017-09-16_01.30.24.png
          2017-09-16_01.30.24.png
          690 kB
        2. 2017-09-16_01.30.36.png
          2017-09-16_01.30.36.png
          278 kB
        3. 2017-09-16_01.30.40.png
          2017-09-16_01.30.40.png
          213 kB
        4. 2017-09-16_01.30.49.png
          2017-09-16_01.30.49.png
          209 kB
        5. 2017-09-16_18.34.43.png
          2017-09-16_18.34.43.png
          357 kB
        6. 2018-07-26_17.39.10.png
          2018-07-26_17.39.10.png
          4.55 MB
        7. AnvilChunkLoader.java
          26 kB
        8. AnvilChunkLoader.zip
          14 kB
        9. hopper_test_world.tbz2
          171 kB
        10. hopper_test_world.zip
          462 kB
        11. MC-119971-fix-simplified.zip
          7 kB

          Issue Links

            Activity

              People

              • Assignee:
                fry [Mojang] Georgii Gavrichev
                Reporter:
                theosib2 Timothy Miller
              • Votes:
                104 Vote for this issue
                Watchers:
                36 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: