MC-10976Async FileSavingProcess will cause chunk overwrites/data loss ( Fix included )
2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!
Hello, this report fixes a saving-bug that has been in minecraft for years.
What is the problem? What happens?
Sometimes Chunks in the world wont be saved or overwritten by a newly generated chunk. The information of these chunks will be lost. This even happens partially without any error messages.
When does this happen?
Very rarely. This is mostly a problem of Servers with a high player count and a bigger playable area. At ~100 Players this problem occurs several times a day. With 10 players this problem might never occur.
What causes this?
The background process that saves already unloaded chunk-data to the specific regionfiles (.mca). This is happening because the service handling the currently opened regionfiles hands out references to files. This breaks synchronization-protocol.
Was this reported before?
Yes, several times without the knowledge of why, where or cause. An example would be MC-10976
Why a new report?
This report contains exact information as to why this happens and how to fix this.
Technical background information
I am using the spigot-namings. See my report here for additional information: https://hub.spigotmc.org/jira/browse/SPIGOT-2385
- FileIOThread is the BackgroundService to save already unloaded Chunks to the specific RegionFile. This service is async
- RegionFileCache holds a bunch of cached RegionFiles for loading/unloading data. FileIOThread regularly inserts data via this. Here is the problem, RegionFileCache hands out references to files!
- ChunkRegionLoader uses RegionFileCache for different lookups/loading/unloading. For example it checks if a chunk already exists in a region file or not very frequently.
When does this problem occur?
Exactly when the RegionFileCache is viewed as "full" and a cleanup is triggered. The cleanup will remove all references to regionfiles from the RegionFileCache and close all regionfiles.
FileIOThread tries to saves data every X milliseconds to a regionfile.
If it already started a new try to save data - thus getting a reference to a file from ChunkRegionLoader - and directly after this the RegionFileCache cleanup is started then the data FileIOThread is saving in that moment will be lost. Additionally it is possible the data gets corrupted and minecraft will generate a fresh chunk at that location the next time it is requested.
How to reproduce?
As a developer this is very easy. Change the RegionFileCache limit from 256 to 2. This will heavily increase the frequency this problem occurs. This should be enough to spam the console with saving-errors.
Reprodution of chunk-regenerations
The best way is to change the limit to 2 as seen above
- Create a flat world and generate enough chunks in an area
- Create a normal world
- Copy all the regionfiles from the flat world to the normal world (dont overwrite the level.dat)
- Start up the server and fly around in gamemode 3.
- The console will be full of errors. About every 1-2 minutes there will be a newly generated chunk will appear in the previously flat area.
How to fix the synchronization/reference problem?
One way to fix this to no longer give out references to files that could be unloaded at any time. Instead the service managing the references should be the only one to know about them.
This is possible with relatively low effort.
As the general implementation of RegionFileCache is faulty the method "c" and "d" need to be rewritten. They are the problem as they hand out references to region files. Instead we can change them to hand out the NBTData directly and mark them syncronized. With this setup the syncronization actually works:
Here is an example that has been tested. Only ~10 lines of code need to be changed in total.
Current implementation
// Kade possibly broken by FileIOThread! too @Deprecated public static DataInputStream c(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.a(i & 31, j & 31); } // Kade is broken by FileIOThread! This will return a reference to a file that may be removed before it is used! @Deprecated public static DataOutputStream d(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.b(i & 31, j & 31); }
Fixed implementation
public static synchronized NBTTagCompound fixedc(File file, int i, int j) throws IOException {
RegionFile regionfile = a(file, i, j);
DataInputStream datainputstream = regionfile.a(i & 31, j & 31);
if (datainputstream == null) return null; // ChunkRegionLoader loadChunk
return NBTCompressedStreamTools.a(datainputstream);
}
public static synchronized void fixedd(File file, int i, int j, NBTTagCompound nbttagcompound) throws IOException {
RegionFile regionfile = a(file, i, j);
DataOutputStream dataoutputstream = regionfile.b(i & 31, j & 31);
NBTCompressedStreamTools.a(nbttagcompound, (DataOutput) dataoutputstream); // from ChunkRegionLoader b(...)
dataoutputstream.close();
}
Let me know if additional information is needed.
Fixed in Spigot:
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e
Environment
Win 7-64
Java 7U15
Linked Issues
is duplicated by5
relates to1
Created Issue:
Single player: "java.io.IOException: Stream Closed" when quitting game
When "Save & Quit to Title" in Single player (quite seldom) an error in the console is thrown :
2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!Environment
Win 7-64
Java 7U15
relates to
MC-12058
relates to
![[Mod] Torabi](../../../data/assets/gravatar/torabi.png){kind=small}
is duplicated by
is duplicated by
![[Mod] redstonehelper](../../../data/avatars/users/10122.svg){kind=small}
is duplicated by
When "Save & Quit to Title" in Single player (quite seldom) an error in the console is thrown :
2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!
Fixed in Spigot:
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e
Single player: "java.io.IOException: Stream Closed" when quitting gameAsync FileSavingProcess will cause chunk overwrites/data loss ( Fix included )
When "Save & Quit to Title" in Single player (quite seldom) an error in the console is thrown :
2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!
Fixed in Spigot:
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e
2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!
Fixed in Spigot:
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!
Hello, this report fixes a saving-bug that has been in minecraft for years.
What is the problem? What happens?
Sometimes Chunks in the world wont be saved or overwritten by a newly generated chunk. The information of these chunks will be lost. This even happens partially without any error messages.When does this happen?
Very rarely. This is mostly a problem of Servers with a high player count and a bigger playable area. At ~100 Players this problem occurs several times a day. With 10 players this problem might never occur.What causes this?
The background process that saves already unloaded chunk-data to the specific regionfiles (.mca). This is happening because the service handling the currently opened regionfiles hands out references to files. This breaks synchronization-protocol.Was this reported before?
Yes, several times without the knowledge of why, where or cause. An example would beMC-10976Why a new report?
This report contains exact information as to why this happens and how to fix this.Technical background information
I am using the spigot-namings. See my report here for additional information: https://hub.spigotmc.org/jira/browse/SPIGOT-2385
- FileIOThread is the BackgroundService to save already unloaded Chunks to the specific RegionFile. This service is async
- RegionFileCache holds a bunch of cached RegionFiles for loading/unloading data. FileIOThread regularly inserts data via this. Here is the problem, RegionFileCache hands out references to files!
- ChunkRegionLoader uses RegionFileCache for different lookups/loading/unloading. For example it checks if a chunk already exists in a region file or not very frequently.
When does this problem occur?
Exactly when the RegionFileCache is viewed as "full" and a cleanup is triggered. The cleanup will remove all references to regionfiles from the RegionFileCache and close all regionfiles.FileIOThread tries to saves data every X milliseconds to a regionfile.
If it already started a new try to save data - thus getting a reference to a file from ChunkRegionLoader - and directly after this the RegionFileCache cleanup is started then the data FileIOThread is saving in that moment will be lost. Additionally it is possible the data gets corrupted and minecraft will generate a fresh chunk at that location the next time it is requested.How to reproduce?
As a developer this is very easy. Change the RegionFileCache limit from 256 to 2. This will heavily increase the frequency this problem occurs. This should be enough to spam the console with saving-errors.Reprodution of chunk-regenerations
The best way is to change the limit to 2 as seen above
- Create a flat world and generate enough chunks in an area
- Create a normal world
- Copy all the regionfiles from the flat world to the normal world (dont overwrite the level.dat)
- Start up the server and fly around in gamemode 3.
- The console will be full of errors. About every 1-2 minutes there will be a newly generated chunk will appear in the previously flat area.
How to fix the synchronization/reference problem?
One way to fix this to no longer give out references to files that could be unloaded at any time. Instead the service managing the references should be the only one to know about them.
This is possible with relatively low effort.As the general implementation of RegionFileCache is faulty the method "c" and "d" need to be rewritten. They are the problem as they hand out references to region files. Instead we can change them to hand out the NBTData directly and mark them syncronized. With this setup the syncronization actually works:
Here is an example that has been tested. Only ~10 lines of code need to be changed in total.
Current implementation
// Kade possibly broken by FileIOThread! too @Deprecated public static DataInputStream c(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.a(i & 31, j & 31); } // Kade is broken by FileIOThread! This will return a reference to a file that may be removed before it is used! @Deprecated public static DataOutputStream d(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.b(i & 31, j & 31); }Fixed implementation
public static synchronized NBTTagCompound fixedc(File file, int i, int j) throws IOException { RegionFile regionfile = a(file, i, j); DataInputStream datainputstream = regionfile.a(i & 31, j & 31); if (datainputstream == null) return null; // ChunkRegionLoader loadChunk return NBTCompressedStreamTools.a(datainputstream); } public static synchronized void fixedd(File file, int i, int j, NBTTagCompound nbttagcompound) throws IOException { RegionFile regionfile = a(file, i, j); DataOutputStream dataoutputstream = regionfile.b(i & 31, j & 31); NBTCompressedStreamTools.a(nbttagcompound, (DataOutput) dataoutputstream); // from ChunkRegionLoader b(...) dataoutputstream.close(); }Let me know if additional information is needed.
Fixed in Spigot:
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e
is duplicated by
![[Mod] Neko](../../../data/avatars/users/92901.png){kind=small}
![[Mod] violine1101](../../../data/avatars/users/92858.png){kind=small}
relates to
is duplicated by
relates to
![[Mod] Michael Wobst](../../../data/avatars/users/37868.png){kind=small}
![[Mod] tryashtar](../../../data/avatars/users/41963.png){kind=small}
![[Mojang] Nathan Adams](../../../data/assets/gravatar/dinnerbone.png){kind=small}
2013-03-04 20:39:03 [SERVER] [INFO] Preparing start region for level 0 loading single player 2013-03-04 20:39:04 [SERVER] [INFO] Kumasasa[/127.0.0.1:0] logged in with entity id 164 at (181.97781539067591, 71.5, -108.6714197356012) 2013-03-04 20:39:58 [SERVER] [INFO] Saving and pausing game... 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:58 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:39:59 [SERVER] [INFO] Stopping server 2013-03-04 20:39:59 [SERVER] [INFO] Saving players java.io.IOException: Stream Closed at java.io.RandomAccessFile.write(Native Method) at java.io.RandomAccessFile.writeInt(Unknown Source) at aca.a(SourceFile:307) at aca.a(SourceFile:249) at acb.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(Unknown Source) at java.io.FilterOutputStream.close(Unknown Source) at acd.a(SourceFile:137) at acd.c(SourceFile:125) at akp.b(SourceFile:29) at akp.run(SourceFile:22) at java.lang.Thread.run(Unknown Source) 2013-03-04 20:39:59 [SERVER] [INFO] Saving worlds 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Overworld 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/Nether 2013-03-04 20:39:59 [SERVER] [INFO] Saving chunks for level 'Test-Welt'/The End 2013-03-04 20:40:00 [CLIENT] [INFO] Stopping!
Hello, this report fixes a saving-bug that has been in minecraft for years.
What is the problem? What happens?
Sometimes Chunks in the world wont be saved or overwritten by a newly generated chunk. The information of these chunks will be lost. This even happens partially without any error messages.
When does this happen?
Very rarely. This is mostly a problem of Servers with a high player count and a bigger playable area. At ~100 Players this problem occurs several times a day. With 10 players this problem might never occur.
What causes this?
The background process that saves already unloaded chunk-data to the specific regionfiles (.mca). This is happening because the service handling the currently opened regionfiles hands out references to files. This breaks synchronization-protocol.
Was this reported before?
Yes, several times without the knowledge of why, where or cause. An example would be MC-10976
Why a new report?
This report contains exact information as to why this happens and how to fix this.
Technical background information
I am using the spigot-namings. See my report here for additional information: https://hub.spigotmc.org/jira/browse/SPIGOT-2385
- FileIOThread is the BackgroundService to save already unloaded Chunks to the specific RegionFile. This service is async
- RegionFileCache holds a bunch of cached RegionFiles for loading/unloading data. FileIOThread regularly inserts data via this. Here is the problem, RegionFileCache hands out references to files!
- ChunkRegionLoader uses RegionFileCache for different lookups/loading/unloading. For example it checks if a chunk already exists in a region file or not very frequently.
When does this problem occur?
Exactly when the RegionFileCache is viewed as "full" and a cleanup is triggered. The cleanup will remove all references to regionfiles from the RegionFileCache and close all regionfiles.
FileIOThread tries to saves data every X milliseconds to a regionfile.
If it already started a new try to save data - thus getting a reference to a file from ChunkRegionLoader - and directly after this the RegionFileCache cleanup is started then the data FileIOThread is saving in that moment will be lost. Additionally it is possible the data gets corrupted and minecraft will generate a fresh chunk at that location the next time it is requested.
How to reproduce?
As a developer this is very easy. Change the RegionFileCache limit from 256 to 2. This will heavily increase the frequency this problem occurs. This should be enough to spam the console with saving-errors.
Reprodution of chunk-regenerations
The best way is to change the limit to 2 as seen above
- Create a flat world and generate enough chunks in an area
- Create a normal world
- Copy all the regionfiles from the flat world to the normal world (dont overwrite the level.dat)
- Start up the server and fly around in gamemode 3.
- The console will be full of errors. About every 1-2 minutes there will be a newly generated chunk will appear in the previously flat area.
How to fix the synchronization/reference problem?
One way to fix this to no longer give out references to files that could be unloaded at any time. Instead the service managing the references should be the only one to know about them.
This is possible with relatively low effort.
As the general implementation of RegionFileCache is faulty the method "c" and "d" need to be rewritten. They are the problem as they hand out references to region files. Instead we can change them to hand out the NBTData directly and mark them syncronized. With this setup the syncronization actually works:
Here is an example that has been tested. Only ~10 lines of code need to be changed in total.
Current implementation
// Kade possibly broken by FileIOThread! too @Deprecated public static DataInputStream c(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.a(i & 31, j & 31); } // Kade is broken by FileIOThread! This will return a reference to a file that may be removed before it is used! @Deprecated public static DataOutputStream d(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.b(i & 31, j & 31); }
Fixed implementation
public static synchronized NBTTagCompound fixedc(File file, int i, int j) throws IOException {
RegionFile regionfile = a(file, i, j);
DataInputStream datainputstream = regionfile.a(i & 31, j & 31);
if (datainputstream == null) return null; // ChunkRegionLoader loadChunk
return NBTCompressedStreamTools.a(datainputstream);
}
public static synchronized void fixedd(File file, int i, int j, NBTTagCompound nbttagcompound) throws IOException {
RegionFile regionfile = a(file, i, j);
DataOutputStream dataoutputstream = regionfile.b(i & 31, j & 31);
NBTCompressedStreamTools.a(nbttagcompound, (DataOutput) dataoutputstream); // from ChunkRegionLoader b(...)
dataoutputstream.close();
}
Let me know if additional information is needed.
Fixed in Spigot:
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e
Maybe related to MC-10976
Do you have enough free space on your partition?
Looks like a regression of MC-10976
Reopened MC-10976.
Dupe of MC-10976
Confirmed for
- 15w36d
Seems to affect only certain chunks
Affected blocks are:
- Accacia leaves (displaying other blocks)
- Oak stairs facing west
- Fences (not loading)
- Probably every other blocks
Blocks being loaded instead:
- Doors
- Wooden Pressure plates
- Eventually every other block
What I experienced was that sometimes when loading the world but else when going maybe 100 blocks away (to another village in the North) and then coming back again causes it as well. After placing white wool above affected leaves, the wool is now loaded sometimes as other blocks as well or does not load at all, however the originally affected block below it seem now unaffected. In the other village two fence pieces are affected, which did not load at all. However the affected blocks are always in one chunk, same blocks next to them but in another chunk are unaffected. This issue is clientside but it really loads the blocks as wrong blocks. Middle clicking on them gives you the block being loaded. Placing another block in that chunk (?) but not directly attached to the not loading blocks causes them to load this block.
I experience also MC-10976 and I got now twice an error when starting the world:
[12:26:31] [Server thread/INFO]: Starting integrated minecraft server version 15w36d [12:26:31] [Server thread/INFO]: Generating keypair java.lang.NullPointerException at ux.a(SourceFile:401) at uz.a(SourceFile:213) at ayk.a(SourceFile:50) at ll.b(SourceFile:153) at bvd.a(SourceFile:98) at bvd.j(SourceFile:130) at net.minecraft.server.MinecraftServer.run(SourceFile:427) at java.lang.Thread.run(Thread.java:745) [12:26:32] [Server thread/INFO]: Preparing start region for level 0 [12:26:33] [Server thread/INFO]: Preparing spawn area: 34% [12:26:34] [Server thread/INFO]: Changing view distance to 12, from 10 [12:26:34] [Server thread/INFO]: Marcono1234[local:E:d026f45e] logged in with entity id 11 at (-1953.217685604307, 80.18696785535857, -1004.2604443552581) [12:26:34] [Server thread/INFO]: Marcono1234 joined the game
What is know
- Client side bug where the client loads the wrong blocks (it is not caused by resource packs)
- Affects only certain chunks and only one block type
- Blocks either do not load or load as other blocks
- Right-clicking the blocks loads them (similar to ghost blocks)
- The loaded blocks seems to be the last changed blocks (opening a door next to not loading blocks causes them to load as door)
How to reproduce
- Create a new world with these settings:
Type: Large Biomes Seed: 1813652467898983630
- /tp -1950 79 -998 and wait until the world has loaded
- You either see already the bug, or you have to move about 100 blocks away, stay there a little bit and then come back (Render distance 12 chunks)
Confirmed for
- 15w36d However I do not know how to reproduce. I experience also
MC-10976. This happened in a superflat world with this settings:- Presets: 3;minecraft:bedrock,minecraft:grass;1;
- Seed: -5699127479337880198
I also attached the world as "Affected world (15w36d).zip" (When you open it, you will not see the error anymore, but maybe somewhere in the level.dat file there is some important information)
[12:58:36] [Server thread/INFO]: Starting integrated minecraft server version 15w36d [12:58:36] [Server thread/INFO]: Generating keypair [12:58:37] [Server thread/INFO]: Preparing start region for level 0 [12:58:37] [Server thread/INFO]: Changing view distance to 12, from 10 [12:58:37] [Server thread/INFO]: Marcono1234[local:E:54dfd5a6] logged in with entity id 3330535 at (609.5, 2.0, -170.5) [12:58:37] [Server thread/INFO]: Marcono1234 joined the game [12:58:38] [Server thread/INFO]: Saving and pausing game... [12:58:38] [Server thread/INFO]: Saving chunks for level 'Enderdragon Test'/Overworld [12:58:38] [Server thread/INFO]: Saving chunks for level 'Enderdragon Test'/Nether [12:58:38] [Server thread/INFO]: Saving chunks for level 'Enderdragon Test'/The End [12:58:41] [Client thread/FATAL]: Error executing task java.util.concurrent.ExecutionException: java.util.ConcurrentModificationException at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_25] at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_25] at g.a(SourceFile:46) [15w36d.jar:?] at azo.as(SourceFile:921) [15w36d.jar:?] at azo.a(SourceFile:378) [15w36d.jar:?] at net.minecraft.client.main.Main.main(SourceFile:125) [15w36d.jar:?] Caused by: java.util.ConcurrentModificationException at java.util.HashMap$HashIterator.nextNode(HashMap.java:1429) ~[?:1.8.0_25] at java.util.HashMap$KeyIterator.next(HashMap.java:1453) ~[?:1.8.0_25] at nn.<init>(SourceFile:27) ~[15w36d.jar:?] at aqr.<init>(SourceFile:82) ~[15w36d.jar:?] at bhs.c(SourceFile:50) ~[15w36d.jar:?] at bhu.b(SourceFile:160) ~[15w36d.jar:?] at bhr.a(SourceFile:514) ~[15w36d.jar:?] at gp.a(SourceFile:68) ~[15w36d.jar:?] at gp.a(SourceFile:11) ~[15w36d.jar:?] at fh$1.run(SourceFile:13) ~[15w36d.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_25] at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_25] at g.a(SourceFile:45) ~[15w36d.jar:?] ... 3 more [12:58:48] [Server thread/INFO]: Marcono1234 has just earned the achievement [Taking Inventory] [12:58:48] [Client thread/INFO]: [CHAT] Marcono1234 has just earned the achievement [Taking Inventory]
Duplicates MC-10976
Hello, this report fixes a saving-bug that has been in minecraft for years.
What is the problem? What happens?
Sometimes Chunks in the world wont be saved or overwritten by a newly generated chunk. The information of these chunks will be lost. This even happens partially without any error messages.
When does this happen?
Very rarely. This is mostly a problem of Servers with a high player count and a bigger playable area. At ~100 Players this problem occurs several times a day. With 10 players this problem might never occur.
What causes this?
The background process that saves already unloaded chunk-data to the specific regionfiles (.mca). This is happening because the service handling the currently opened regionfiles hands out references to files. This breaks synchronization-protocol.
Was this reported before?
Yes, several times without the knowledge of why, where or cause. An example would be MC-10976
Why a new report?
This report contains exact information as to why this happens and how to fix this.
Technical background information
I am using the spigot-namings. See my report here for additional information: https://hub.spigotmc.org/jira/browse/SPIGOT-2385
- FileIOThread is the BackgroundService to save already unloaded Chunks to the specific RegionFile. This service is async
- RegionFileCache holds a bunch of cached RegionFiles for loading/unloading data. FileIOThread regularly inserts data via this. Here is the problem, RegionFileCache hands out references to files!
- ChunkRegionLoader uses RegionFileCache for different lookups/loading/unloading. For example it checks if a chunk already exists in a region file or not very frequently.
When does this problem occur?
Exactly when the RegionFileCache is viewed as "full" and a cleanup is triggered. The cleanup will remove all references to regionfiles from the RegionFileCache and close all regionfiles.
FileIOThread tries to saves data every X milliseconds to a regionfile.
If it already started a new try to save data - thus getting a reference to a file from ChunkRegionLoader - and directly after this the RegionFileCache cleanup is started then the data FileIOThread is saving in that moment will be lost. Additionally it is possible the data gets corrupted and minecraft will generate a fresh chunk at that location the next time it is requested.
How to reproduce?
As a developer this is very easy. Change the RegionFileCache limit from 256 to 2. This will heavily increase the frequency this problem occurs. This should be enough to spam the console with saving-errors.
Reprodution of chunk-regenerations
The best way is to change the limit to 2 as seen above
- Create a flat world and generate enough chunks in an area
- Create a normal world
- Copy all the regionfiles from the flat world to the normal world (dont overwrite the level.dat)
- Start up the server and fly around in gamemode 3.
- The console will be full of errors. About every 1-2 minutes there will be a newly generated chunk will appear in the previously flat area.
How to fix the synchronization/reference problem?
One way to fix this to no longer give out references to files that could be unloaded at any time. Instead the service managing the references should be the only one to know about them.
This is possible with relatively low effort.
As the general implementation of RegionFileCache is faulty the method "c" and "d" need to be rewritten. They are the problem as they hand out references to region files. Instead we can change them to hand out the NBTData directly and mark them syncronized. With this setup the syncronization actually works:
Here is an example that has been tested. Only ~10 lines of code need to be changed in total.
Current implementation
// Kade possibly broken by FileIOThread! too @Deprecated public static DataInputStream c(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.a(i & 31, j & 31); } // Kade is broken by FileIOThread! This will return a reference to a file that may be removed before it is used! @Deprecated public static DataOutputStream d(File file, int i, int j) { RegionFile regionfile = a(file, i, j); return regionfile.b(i & 31, j & 31); }
Fixed implementation
public static synchronized NBTTagCompound fixedc(File file, int i, int j) throws IOException {
RegionFile regionfile = a(file, i, j);
DataInputStream datainputstream = regionfile.a(i & 31, j & 31);
if (datainputstream == null) return null; // ChunkRegionLoader loadChunk
return NBTCompressedStreamTools.a(datainputstream);
}
public static synchronized void fixedd(File file, int i, int j, NBTTagCompound nbttagcompound) throws IOException {
RegionFile regionfile = a(file, i, j);
DataOutputStream dataoutputstream = regionfile.b(i & 31, j & 31);
NBTCompressedStreamTools.a(nbttagcompound, (DataOutput) dataoutputstream); // from ChunkRegionLoader b(...)
dataoutputstream.close();
}
Let me know if additional information is needed.
Added all your stuff including summary to MC-10976.
Edit: Bugtracker-wise it's not useful to make 2 tickets for the same issue and the older ticket has more watchers and duplicates / relates links.
Possibly caused by MC-10976. The bug described there was already present in minecraft 1.4.x
The bug
Multiple methods call java.lang.Throwable.printStackTrace() instead of properly logging an error with the exception as parameter. This causes the error to be logged as "INFO" and to have [STDERR]: as prefix.
How to reproduce
Try to reproduce one of the following bugs
Important: These are not the only occurrences of this bug, they are just examples. Who ever fixes this should search for all occurrences of java.lang.Throwable.printStackTrace(); there are also multiple in the realms classes.
Turns out this is actually a years old bug, MC-10976. A fix has been attempted twice, but it's still there.
I've resolved your ticket as a duplicate of that report, as we don't want to have multiple tickets about the same issue and MC-10976 also includes a proposed fix which makes resolving this bug even easier. Maybe this bug will be fixed in 1.13.
Please do not mark issues as private, unless your bug report is an exploit or contains information about your username or server.
Looks like MC-10976 to me.
Thank you for your report!
However, this issue has been temporarily closed as Awaiting Response.
We do not have enough information to find the cause of this issue.
Please attach the game log found in .minecraft/logs/latest.log here.
Click here to find out where your .minecraft folder is.
Once you have attached the game log, the report will be reopened automatically.
Quick Links:
📓 Issue Guidelines – 💬 Community Support – 📧 Customer Support – 📖 Game Wiki
![[Mod] Jiingy](../../../data/avatars/users/91802.png){kind=small}
I have a similar issue on vanilla minecraft-1.4.7 SSP:
asdf 27 achievements 210 recipes Setting user: xxxxxxxx, xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx LWJGL Version: 2.8.5 Starting up SoundSystem... Initializing LWJGL OpenAL (The LWJGL binding of OpenAL. For more information, see http://www.lwjgl.org) OpenAL initialized. мар 07, 2013 11:54:44 AM bdz c INFO: Starting integrated minecraft server version 1.4.7 мар 07, 2013 11:54:44 AM bdz c INFO: Generating keypair мар 07, 2013 11:54:44 AM net.minecraft.server.MinecraftServer e INFO: Preparing start region for level 0 мар 07, 2013 11:54:45 AM gm a INFO: xxxxxxxx[/127.0.0.1:0] logged in with entity id 391 at (134.8549919735036, 71.0, 228.0527640955616) мар 07, 2013 12:18:32 PM bdz q INFO: Saving and pausing game... мар 07, 2013 12:18:32 PM net.minecraft.server.MinecraftServer a INFO: Saving chunks for level 'My First World'/Overworld мар 07, 2013 12:18:32 PM net.minecraft.server.MinecraftServer a INFO: Saving chunks for level 'My First World'/Nether мар 07, 2013 12:18:32 PM net.minecraft.server.MinecraftServer a INFO: Saving chunks for level 'My First World'/The End мар 07, 2013 12:18:38 PM iv a INFO: xxxxxxxx lost connection: disconnect.quitting мар 07, 2013 12:18:38 PM iv a INFO: Stopping singleplayer server as player logged out мар 07, 2013 12:18:38 PM net.minecraft.server.MinecraftServer k INFO: Stopping server мар 07, 2013 12:18:38 PM net.minecraft.server.MinecraftServer k INFO: Saving players мар 07, 2013 12:18:38 PM net.minecraft.server.MinecraftServer k INFO: Saving worlds мар 07, 2013 12:18:38 PM net.minecraft.server.MinecraftServer a INFO: Saving chunks for level 'My First World'/Overworld мар 07, 2013 12:18:38 PM net.minecraft.server.MinecraftServer a INFO: Saving chunks for level 'My First World'/Nether мар 07, 2013 12:18:38 PM net.minecraft.server.MinecraftServer a INFO: Saving chunks for level 'My First World'/The End java.io.IOException: Stream Closed at java.io.RandomAccessFile.seek(Native Method) at aaj.a(SourceFile:306) at aaj.a(SourceFile:249) at aak.close(SourceFile:230) at java.util.zip.DeflaterOutputStream.close(DeflaterOutputStream.java:241) at java.io.FilterOutputStream.close(FilterOutputStream.java:160) at aam.a(SourceFile:137) at aam.c(SourceFile:125) at aiw.b(SourceFile:29) at aiw.run(SourceFile:22) at java.lang.Thread.run(Thread.java:722) Stopping! SoundSystem shutting down... Author: Paul Lamb, www.paulscode.comNotes:
------
OS: CentOS 6
Java version: java-1.7.0-openjdk-1.7.0.9-2.3.7.1.el6_3.x86_64
I had to modify installed game according to http://blog.aloneunix.ru/2012/03/minecraft-liblwjglso-wrong-elf-class.html
Just happended with Launcher 0.6:
Can no longer observe this in newer snapshots 13w22 / 13w23. Anyone else ?
Still happens in vanilla 1.6.2
Bootstrap (v5)
Current time is Aug 2, 2013 6:50:45 PM
System.getProperty('os.name') == 'Linux'
System.getProperty('os.version') == '2.6.32-358.14.1.el6.x86_64'
System.getProperty('os.arch') == 'amd64'
System.getProperty('java.version') == '1.7.0_25'
System.getProperty('java.vendor') == 'Oracle Corporation'
System.getProperty('sun.arch.data.model') == '64'
...
Client> 2013-08-02 19:35:05 [SERVER] [INFO] Saving worlds
Client> 2013-08-02 19:35:05 [SERVER] [INFO] Saving chunks for level 'My First World'/Overworld
Client> java.io.IOException: Stream Closed
Client> at java.io.RandomAccessFile.seek(Native Method)
Client> at aea.a(SourceFile:308)
Client> at aea.a(SourceFile:251)
Client> at aeb.close(SourceFile:232)
Client> at java.util.zip.DeflaterOutputStream.close(DeflaterOutputStream.java:241)
Client> at java.io.FilterOutputStream.close(FilterOutputStream.java:160)
Client> at aed.a(SourceFile:140)
Client> at aed.c(SourceFile:128)
Client> at amp.b(SourceFile:30)
Client> at amp.run(SourceFile:23)
Client> at java.lang.Thread.run(Thread.java:724)
Client> 2013-08-02 19:35:05 [SERVER] [INFO] Saving chunks for level 'My First World'/Nether
Client> 2013-08-02 19:35:05 [SERVER] [INFO] Saving chunks for level 'My First World'/The End
Client> 2013-08-02 19:35:07 [CLIENT] [INFO] Stopping!
Client>
Client> SoundSystem shutting down...
Client> Author: Paul Lamb, www.paulscode.com
Client>
авг 02, 2013 7:35:07 PM net.minecraft.launcher.process.ProcessMonitorThread run
SEVERE: null
java.io.IOException: Stream closed
at java.io.BufferedReader.ensureOpen(BufferedReader.java:115)
at java.io.BufferedReader.readLine(BufferedReader.java:310)
at java.io.BufferedReader.readLine(BufferedReader.java:382)
at net.minecraft.launcher.process.ProcessMonitorThread.run(ProcessMonitorThread.java:26)
Game ended with no troubles detected (exit code 0)
Still exists in 14w08a, and seems to be directly related to how much time is spent in the world.
I also suggest that the labels "java io exception stop server" be added. I almost posted a duplicate.
Still occuring in 14w21, according to
MC-56591Requesting to be reopened.
Confirmed for 1.8.3 according to
MC-78430, but the creator of that report had anti-virus software installed.@all, uninstall any and all anti-virus software you currently have and check to see if the issue persists.
You mean rather disable, uninstalling anti-virus programs is the last thing you should do
Windows 8.1 Java 1.8, v1.8.8, SSP, vanilla.
I get this often, not all the time.
Always happens while/after saving The End : Might be a clue that I've never been to The End in this world.
No, I will not disable anti-virus.
[13:15:56] [Server thread/INFO]: Stopping server
[13:15:56] [Server thread/INFO]: Saving players
[13:15:56] [Server thread/INFO]: Saving worlds
[13:15:56] [Server thread/INFO]: Saving chunks for level 'Europa'/Overworld
[13:15:56] [Server thread/INFO]: Saving chunks for level 'Europa'/Nether
[13:15:56] [Server thread/INFO]: Saving chunks for level 'Europa'/The End
java.io.IOException: Stream Closed
at java.io.RandomAccessFile.seek0(Native Method)
at java.io.RandomAccessFile.seek(Unknown Source)
at anh.a(SourceFile:315)
at anh.a(SourceFile:255)
at anh$a.close(SourceFile:236)
at java.util.zip.DeflaterOutputStream.close(Unknown Source)
at java.io.FilterOutputStream.close(Unknown Source)
at anj.b(SourceFile:140)
at anj.c(SourceFile:124)
at auc.c(SourceFile:37)
at auc.run(SourceFile:30)
at java.lang.Thread.run(Unknown Source)
[13:16:45] [Client thread/INFO]: Stopping!
[13:16:45] [Client thread/INFO]: SoundSystem shutting down...
[13:16:45] [Client thread/WARN]: Author: Paul Lamb, www.paulscode.com
It looks like the writeChunkNBTTags(AnvilChunkLoader.PendingChunk p_75821_1_) method (which closes the file) of the net.minecraft.world.chunk.storage.AnvilChunkLoader class is called before the write(int p_76712_1_, byte[] p_76712_2_, int p_76712_3_) method (which tries to write to the file) of the net.minecraft.world.chunk.storage.RegionFile class (MCP 1.8 names).
Confirmed for
Confirmed for
Confirmed for
Confirmed for
https://hub.spigotmc.org/jira/browse/SPIGOT-2385
https://hub.spigotmc.org/stash/projects/SPIGOT/repos/craftbukkit/commits/7f1a32252b4fc48bad17ab3e1fc0399ce451f15e
Confirmed "Stream closed" for
Confirmed "Stream closed" for
Can confirm in 1.11.2
Saw this in 1.12.2
This is also affecting every 1.13 snapshot.
LuxiKeks, do you have steps to reproduce (except "Save & Quit")?
What are the circumstances?
Flatworld ? Much Redstone?
Slow disk?
Please force a crash by pressing F3 + C for 10 seconds while in-game and attach the crash report (minecraft/crash-reports/crash-<DATE>-client.txt) here.
I attempted several times to reproduce this in 1.13, didn't get any stream closed errors, it seems to be fixed
user-a6b77, the comment of LuxiKeks above is telling the exact opposite.
I haven't checked if this happens in 1.13 snapshots, but I couldn't reproduce it in the official 1.13 release following the steps above
Will wait for other opinions (or even an "fixed" statement of Mojang) before resolving this as fixed.
That code was reorganized somewhere before 1.14 and no longer lets files escape cache. Also, chunk IO thread is gone. So this issue is fixed.