[MC-44874] Lag near villages

Noticed a definite increase in lag in comparison to 1.7.4. Java process used > 100% as reported by "top" shell command. Monitoring CPU usage while a single player traveled around indicated it was related to proximity to villages. Lag did not occur in Nether, The End, or at places distant from Villages. Lag increased as size of village increased. CPU usage was almost entirely in a single java thread (as reported by "top").

Related issues

duplicates

MC-44890 Doors get added to the list of village doors over and over again

Comments

CubeTheThird 2014-01-14T01:53:05Z

What is your exact java installation version? (command: java -version).
Also:
Please attach the complete output of the "Development console" which can be found on the second tab of the launcher.

If the launcher closes after game start, please edit your profile and select "Launcher visibility" then, "Keep the launcher open".

migrated 2014-01-14T02:06:06Z

In case I was not clear before, the high CPU usage is on the server, not the client.

Server launch command:
java -Xmx1024M -Xms1024M -d64 -jar /usr/games/minecraft/latest nogui

Output of java -version:
java version "1.7.0_45"
Java(TM) SE Runtime Environment (build 1.7.0_45-b18)
Java HotSpot(TM) 64-Bit Server VM (build 24.45-b08, mixed mode)

Client-side Console output:
[20:59:35 INFO]: Minecraft Launcher 1.3.8 (through bootstrap 4) started on windows...
[20:59:35 INFO]: Refreshing local version list...
[20:59:35 INFO]: Current time is Jan 13, 2014 8:59:35 PM
[20:59:35 INFO]: System.getProperty('os.name') == 'Windows Vista'
[20:59:35 INFO]: System.getProperty('os.version') == '6.0'
[20:59:35 INFO]: System.getProperty('os.arch') == 'x86'
[20:59:35 INFO]: System.getProperty('java.version') == '1.7.0_25'
[20:59:35 INFO]: System.getProperty('java.vendor') == 'Oracle Corporation'
[20:59:35 INFO]: System.getProperty('sun.arch.data.model') == '32'
[20:59:35 INFO]: Refreshing remote version list...
[20:59:36 INFO]: Refresh complete.
[20:59:36 INFO]: Loaded 2 profile(s); selected 'testing'
[20:59:36 INFO]: Refreshing auth...
[20:59:36 INFO]: Logging in with access token
[21:04:22 INFO]: Getting syncinfo for selected version
[21:04:22 INFO]: Queueing library & version downloads
[21:04:22 INFO]: Download job 'Version & Libraries' started (16 threads, 27 files)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\java3d\vecmath\1.3.1\vecmath-1.3.1.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch-platform\5.12\twitch-platform-5.12-natives-windows-32.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch-external-platform\4.5\twitch-external-platform-4.5-natives-windows-32.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch\5.12\twitch-5.12.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\codecwav\20101023\codecwav-20101023.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\net\sf\jopt-simple\jopt-simple\4.5\jopt-simple-4.5.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jinput\jinput-platform\2.0.5\jinput-platform-2.0.5-natives-windows.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\io\netty\netty-all\4.0.10.Final\netty-all-4.0.10.Final.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\commons-io\commons-io\2.4\commons-io-2.4.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\logging\log4j\log4j-api\2.0-beta9\log4j-api-2.0-beta9.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\ibm\icu\icu4j-core-mojang\51.2\icu4j-core-mojang-51.2.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\commons\commons-lang3\3.1\commons-lang3-3.1.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\google\code\gson\gson\2.2.4\gson-2.2.4.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\logging\log4j\log4j-core\2.0-beta9\log4j-core-2.0-beta9.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\mojang\authlib\1.2\authlib-1.2.jar for job 'Version & Libraries'... (try 0)
[21:04:22 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\codecjorbis\20101023\codecjorbis-20101023.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Download job 'Resources' skipped as there are no files to download
[21:04:23 INFO]: Job 'Resources' finished successfully (took 0:00:00.000)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch-external-platform\4.5\twitch-external-platform-4.5-natives-windows-32.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\logging\log4j\log4j-core\2.0-beta9\log4j-core-2.0-beta9.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\ibm\icu\icu4j-core-mojang\51.2\icu4j-core-mojang-51.2.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\io\netty\netty-all\4.0.10.Final\netty-all-4.0.10.Final.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl\2.9.1\lwjgl-2.9.1.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\soundsystem\20120107\soundsystem-20120107.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jutils\jutils\1.0.0\jutils-1.0.0.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\google\guava\guava\15.0\guava-15.0.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\logging\log4j\log4j-api\2.0-beta9\log4j-api-2.0-beta9.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jinput\jinput-platform\2.0.5\jinput-platform-2.0.5-natives-windows.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\net\sf\jopt-simple\jopt-simple\4.5\jopt-simple-4.5.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jinput\jinput\2.0.5\jinput-2.0.5.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\codecjorbis\20101023\codecjorbis-20101023.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\net\sf\trove4j\trove4j\3.0.3\trove4j-3.0.3.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch-platform\5.12\twitch-platform-5.12-natives-windows-32.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\mojang\authlib\1.2\authlib-1.2.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\google\code\gson\gson\2.2.4\gson-2.2.4.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\librarylwjglopenal\20100824\librarylwjglopenal-20100824.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\java3d\vecmath\1.3.1\vecmath-1.3.1.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl-platform\2.9.1\lwjgl-platform-2.9.1-natives-windows.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch\5.12\twitch-5.12.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\libraryjavasound\20101123\libraryjavasound-20101123.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl_util\2.9.1\lwjgl_util-2.9.1.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Attempting to download C:\Users\user\AppData\Roaming\.minecraft\versions\14w02c\14w02c.jar for job 'Version & Libraries'... (try 0)
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\commons\commons-lang3\3.1\commons-lang3-3.1.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\commons-io\commons-io\2.4\commons-io-2.4.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\codecwav\20101023\codecwav-20101023.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\soundsystem\20120107\soundsystem-20120107.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jutils\jutils\1.0.0\jutils-1.0.0.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jinput\jinput\2.0.5\jinput-2.0.5.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl\2.9.1\lwjgl-2.9.1.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl_util\2.9.1\lwjgl_util-2.9.1.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl-platform\2.9.1\lwjgl-platform-2.9.1-natives-windows.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\librarylwjglopenal\20100824\librarylwjglopenal-20100824.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\google\guava\guava\15.0\guava-15.0.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\libraryjavasound\20101123\libraryjavasound-20101123.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\libraries\net\sf\trove4j\trove4j\3.0.3\trove4j-3.0.3.jar for job 'Version & Libraries': Local file matches local checksum, using that
[21:04:23 INFO]: Finished downloading C:\Users\user\AppData\Roaming\.minecraft\versions\14w02c\14w02c.jar for job 'Version & Libraries': Used own copy as it matched etag
[21:04:23 INFO]: Job 'Version & Libraries' finished successfully (took 0:00:00.772)
[21:04:23 INFO]: Launching game
[21:04:23 INFO]: Looking for old natives & assets to clean up...
[21:04:23 INFO]: Unpacking natives to C:\Users\user\AppData\Roaming\.minecraft\versions\14w02c\14w02c-natives-3816395264520760
[21:04:24 INFO]: Launching in C:\Users\user\AppData\Roaming\.minecrafttest
[21:04:24 INFO]: Half command: C:\Program Files\Java\jre7\bin\javaw.exe -XX:HeapDumpPath=MojangTricksIntelDriversForPerformance_javaw.exe_minecraft.exe.heapdump -Xmx512M -Djava.library.path=C:\Users\user\AppData\Roaming\.minecraft\versions\14w02c\14w02c-natives-3816395264520760 -cp C:\Users\user\AppData\Roaming\.minecraft\libraries\java3d\vecmath\1.3.1\vecmath-1.3.1.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\net\sf\trove4j\trove4j\3.0.3\trove4j-3.0.3.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\ibm\icu\icu4j-core-mojang\51.2\icu4j-core-mojang-51.2.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\net\sf\jopt-simple\jopt-simple\4.5\jopt-simple-4.5.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\codecjorbis\20101023\codecjorbis-20101023.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\codecwav\20101023\codecwav-20101023.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\libraryjavasound\20101123\libraryjavasound-20101123.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\librarylwjglopenal\20100824\librarylwjglopenal-20100824.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\paulscode\soundsystem\20120107\soundsystem-20120107.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\io\netty\netty-all\4.0.10.Final\netty-all-4.0.10.Final.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\google\guava\guava\15.0\guava-15.0.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\commons\commons-lang3\3.1\commons-lang3-3.1.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\commons-io\commons-io\2.4\commons-io-2.4.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jinput\jinput\2.0.5\jinput-2.0.5.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\net\java\jutils\jutils\1.0.0\jutils-1.0.0.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\google\code\gson\gson\2.2.4\gson-2.2.4.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\com\mojang\authlib\1.2\authlib-1.2.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\logging\log4j\log4j-api\2.0-beta9\log4j-api-2.0-beta9.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\org\apache\logging\log4j\log4j-core\2.0-beta9\log4j-core-2.0-beta9.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl\2.9.1\lwjgl-2.9.1.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\org\lwjgl\lwjgl\lwjgl_util\2.9.1\lwjgl_util-2.9.1.jar;C:\Users\user\AppData\Roaming\.minecraft\libraries\tv\twitch\twitch\5.12\twitch-5.12.jar;C:\Users\user\AppData\Roaming\.minecraft\versions\14w02c\14w02c.jar net.minecraft.client.main.Main
[21:04:25 INFO]: Client> [21:04:25] [main/INFO]: Setting user: tdjewell
[21:04:25 INFO]: Client> [21:04:25] [main/INFO]: (Session ID is token:e0a76d2a59f34beaafc77dec57fc9f58:f6a585f050e6410b9c3e1a84caf5a1c6)
[21:04:25 INFO]: Client> [21:04:25] [Client thread/INFO]: LWJGL Version: 2.9.1
[21:04:26 INFO]: Client> [21:04:26] [Client thread/INFO]: Reloading ResourceManager: Default
[21:04:26 INFO]: Client> 
[21:04:26 INFO]: Client> Starting up SoundSystem...
[21:04:27 INFO]: Client> Initializing LWJGL OpenAL
[21:04:27 INFO]: Client>     (The LWJGL binding of OpenAL.  For more information, see http://www.lwjgl.org)
[21:04:27 INFO]: Client> OpenAL initialized.
[21:04:27 INFO]: Client> 
[21:04:27 INFO]: Client> [21:04:27] [Sound Library Loader/INFO]: Sound engine started
[21:04:28 INFO]: Client> [21:04:28] [Client thread/INFO]: Created: 1024x512 textures/blocks-atlas
[21:04:28 INFO]: Client> [21:04:28] [Client thread/INFO]: Created: 256x256 textures/items-atlas
[21:04:36 INFO]: Client> [21:04:36] [Client thread/INFO]: Connecting to 96.241.147.59, 25566

CubeTheThird 2014-01-14T02:10:37Z

I ask these for a few reasons: people having used OpenJDK 1.6 have reported issues. Also, sometimes clientside console output reveals details pertaining to lag. That being said, are there any unusual messages appearing in the server's output?

migrated 2014-01-14T02:20:28Z

Only "Can't keep up" messages, tending to be 5K to 11K ms behind, then skipping 50 to 200 ticks.

migrated 2014-01-14T06:10:12Z

I assume this is related to the bug I reported... My situation isn't exactly commonplace, but it should be the same fix...

MC-44620

Also: MC-44531

kumasasa 2014-01-18T09:14:49Z

MC-44890 is fixed for the next snapshot.