Extreme lag when SpongeProfileManager.get() is called on server thread

[AngryCarrot789]

Version

7.0.0

Operating System

Linux/ubuntu

Java Version

1.8.0_312

Plugins/Mods

Additional Banners by DarkhaxDev
Advanced Machines by Chocohead
Advanced Machines Patcher by Su5eD
Advanced Solar Panels by Icedfire, SeNtiMeL, Chocohead
Advanced Solar Panels Patcher by Su5eD
AE2 Stuff by bdew
AE2 Unofficial Extended Life by PrototypeTrousers
Akashic Tome by Vazkii
Ambient Sounds by CreativeMD
AppleSkin by squeek502
Aqua Acrobatics by Fuzs_, embeddedt
Aroma Core by Aroma1997
Aroma Mining World by Aroma1997
ASMC by AstroTibs
AttributeFix by DarkhaxDev
AutoRegLib by Vazkii
Backpacks by Eydamos
Backups by Silly511
Bad Wither No Cookie - Reloaded by Kreezxil, Eleksploded
Baubles by Azanor
BdLib by BDew
Better Ping Display by Quintinity
BiblioCraft by Nuchaz
Binnie's Mods by Binnie567, mezz
Biomes O' Plenty by Forstride, TheAdubbz, Glitchfiend
Blockcraftery by elucent_, EpicSquid319
Blood Magic by WayofTime
Bookshelf by Darkhax
Born in a Barn by Chocohead
Botania by Vazkii
BuildCraft by CovertJaguar, SpaceToad
CC: Tweaked by DanTwoHundred, SquidDev
Charset Crafting by asiekierka
Charset Immersion by asiekierka
Charset Lib by asiekierka
ChatFlow by Vazkii
Chicken Chunks by ChickenBones
ChickenASM by covers1624
Chisel by Automatic_Maiden, tterrag, Drullkus, and Minecreatr
Chisels and Bits by AlgorithmX2
ChunkGenLimiter by barteks2x
Client Tweaks by BlayTheNinth
CodeChickenLib by Chicken_Bones, covers1624
CoFH Core by Team CoFH
CoFH World by TeamCoFH, KingLemming, skyboy026, covers1624
Comforts by TheIllusiveC4
Compact Solars by cpw
Compacter by bdew
Computronics by Asie
ConnectedTexturesMod by tterrag1098
Construct's Armory by TheIllusiveC4
Controlling by jaredlll08
Cooking for Blockheads by BlaytheNinth
CraftTweaker by jaredlll08, StanH
CreativeCore by CreativeMD
Crimson Revelations by MobiusFlip
Cucumber Library by BlakeBr0
Culinary Construct by TheIllusiveC4
Custom Main Menu by Lumien
Custom Starting Gear by brandon3055
Damage Tilt by Charles445
Death Counter by iChun
Debark by asie
Default Options by BlaytheNinth
Default World Generator by EzTerry, FireBall1725
Diet Hoppers by RWTema
Ding by iChun
Doge by mmdanggg2
DupeFix Project by Focamacho
Dynamic Lights by AtomicStryker
Enchanting Plus by LCLC98, Freyadono, Darkhax
Enchantment Descriptions by DarkhaxDev
Ender IO by CrazyPants
Ender Storage by EcuTruin, Chickenbones, covers1624
Ender Zoo by CrazyPants
EnderCore by tterag1098
Energy Converters by xalcon
Entity Culling by Meldexun
Entity Desync Fix by Meldexun
Exchangers by Jackyy
Extra Cells by Leonelf
Extra Utilities by RWTema
ExtraPlanets by MJRLegends
ExtremeReactors by ZeroNoRyouki
Fairy Lights by pau101
Fast Leaf Decay by Olafski
FastWorkbench by Shadows_of_Fire
Featured Servers by Jake_Evans
Fence Jumper by TheRealp455w0rd
Fix Experience Bug by MacTso, Lupicus
FoamFix by Asie
Forestry by SirSengir, Covert_Jaguar, MysteriousAges, mezz
Forge Multipart CBE by Chicken_Bones, MrTJP, covers1624
Funky Locomotion by RWTema
Galacticraft by micdoodle8, teamgalacticraft, ROMVoid95
Gas Conduits by pupnewfster
Gendustry by BDew
Gendustry JEI Addon by ninjabrain1
GooglyEyes by iChun
Gravitation Suite by SeNtiMeL, Chocohead
Gravitation Suite Patcher by Su5eD
Growthcraft Community Edition by Gwafu, Alatyami
Guide-API by TehNut, Tombenpotter
Guidebook by gigaherz
GunpowderLib by Jackyy
Had Enough Items by mezz, CleanroomMC, Rongmario
Hat Stand by iChun
Hats by iChun
HelpFixer by MatthewPrenger
HT's TreeChop by hammertater
Hwyla by ProfMobius, TehNut
IC2 Patcher by Su5eD
ICBM - Classic by Calclavia, DarkGuardsman
iChunUtil by iChun
IFPatcher by eve0415
Industrial Foregoing by Buuz135
IndustrialCraft² by sfPlayer1, Aroma1997, Chocohead, estebess
Integration Foregoing by Buuz135, Jackyy
Inventory Tweaks by Kobata
Iron Chests by cpw, ProgWML6, Alexbegt
It's The Little Things by Zlepper
IvToolkit by Ivorius
JAOPCA by TheLMiffy1111
JEI Bees by bdew
JEI Integration by tonius11, SnowShock35
Jon's Exclusives by Jon
Just Enough Drags by warmthdawn
Just Enough Energistics by TheRealp455w0rd
Just Enough HarvestCraft by mrAppleXZ
Just Enough Pattern Banners by Lorexe
Just Enough Reactors by BrainStone
Just Enough Resources by way2muchnoise
Just Enough Throwing In Fluids by Lykrast
JustEnoughIDs by Runemoro, ZombieHDGaming
KleeSlabs by BlayTheNinth
LemonLib by Lemonszz
Let Sleeping Dogs Lie by ohaiiChun
Linking Through the Ages (LTTA) by IAmTheFloydman
Login Shield by Glasspelican
Logistics Pipes by mc_rs485, theZoro266, davboecki
LoliASM by Rongmario
Long Fall Boots by Nano_Heart
LootTweaker by Daomephsta
Lost Magic by Spiteful_Fox
LunatriusCore by Lunatrius
Magic Bees by MysteriousAges
Main Menu Scale by modmuss50
Mantle by mDiyo, ProgWML6, bonusboni
MCMultiPart by amadornes, 2xsaiko
Mekanism by aidancbrady
MekanismGenerators by aidancbrady
MekanismTools by aidancbrady
MixinBooter by Rongmario
MJRLegends Lib by MJRLegends
MmmMmmMmmMmm by boni
Modular Powersuits by MachineMuse
Modular Routers by desht_08
More Overlays by FeldiM245
Morph by iChun
Morph-o-Tool by Vazkii
Morpheus by Quetzi
Mouse Tweaks by YaLTeR97
MrCrayfish's Furniture Mod by MrCrayfish
MrTJPCore by MrTJP
Mystcraft by XCompWiz
Mystcraft Info by Veovis_Muaddib, IAmTheFloydman
Mystical Agriculture by BlakeBr0
MysticalLib by elucent_, EpicSquid319, Noobanidus, Martacus, Davoleo_K
Natura by mDiyo, ProgWML6, Alexbegt
Nature's Compass by Chaosyr
Netherending Ores by ic_trab
NetherPortalFix by BlayTheNinth
No Recipe Book by Seneschal_Luwin
NoMoreRecipeConflict by stimmedcow, GotoLink
Numina by MachineMuse
OMLib by voltyfarstar, Keridos
Open Modular Turrets by Poenjabiesous, voltyfarstar, Keridos
OpenBlocks by OpenMods Team
OpenComputers by Sangar
OpenComputers ICBM Addon by TheEternalSoap
OpenEye by OpenMods Team
OpenModsLib by OpenMods Team
Pack Crash Info by BloodWorkXGaming
Pam's Harvestcraft by MatrexsVigil, pamharvestcraft
Patchouli by Vazkii
Picture in Picture by iChun
Placebo by Shadows_of_Fire
Planet Progression by MJRLegends
Player Plates by Gaz_
Plethora Peripherals by SquidDev
PlusTiC by landmaster_phuong0429
PneumaticCraft by MineMaarten, desht_08
Portal Gun by iChun
Project Red - Base by MrTJP, covers1624
Project Red - Compact by MrTJP, covers1624
Project Red - Fabrication by MrTJP, covers1624
Project Red - Integration by MrTJP, covers1624
Project Red - Lighting by MrTJP, covers1624
Project Red - Mechanical by MrTJP, covers1624
Project Red - World by MrTJP, covers1624
Quark by Vazkii, wiiv
Railcraft by CovertJaguar
RandomPatches by TheRandomLabs
Reach Fix by Meldexun
ReAuth by TechnicianLP
Reborn Core by modmuss50, GigaBit101, ProspectorDev
Recurrent Complex by Ivorius
Redstone Arsenal by Team CoFH
Redstone Flux by KingLemming
Reliquary by TheMike, x3n0ph0b3, P3pp3rF1y
Resource Loader by Lumien
Roguelike Dungeons by Greymerk
Save My Stronghold! by YUNGNICKYOUNG
Schematica by Luantrius
Shadowfacts' Forgelin by ShadowfactsDev
Simply Jetpacks by Tonius
Smooth Font by bre2el
Smooth Scrolling Everywhere by shedaniel
Sound Device Options by ichttt
SplashAnimation by Asie
Statues by Automatic_Maiden, Asiekierka, Lemonszz
Steve's Carts Reborn by modmuss50
Super Factory Manager by TeamDman
Super Sound Muffler: Revived by EdgarAllen, Firstnecron
Tesla Core Lib by face_of_cat
Thaumcraft by Azanor
Thaumic Augmentation by TheCodex6824, TechnoMysterio
Thaumic Energistics by Nividica, BrockWS, TheRealp455w0rd
Thaumic JEI by Buuz135
Thaumic Tinkerer by pixlepix, Nekosune
The Twilight Forest by Benimatic, williewillus, Drullkus, Tamaized, AtomicBlom
Thermal Cultivation by TeamCoFH, KingLemming
Thermal Dynamics by Team CoFH
Thermal Expansion by Team CoFH
Thermal Foundation by TeamCoFH
Thermal Innovation by TeamCoFH
Tinker's JEI by Possible_triangle
Tinkers Construct by mDiyo, boni, KnightMiner
Tinkers OreDict Cache by youyihj
Tinkers' Addons by oitsjustjose
TipTheScales by Jaredlll08
Toast Control by Shadows_of_Fire
Torchmaster by xalcon
Translocators by ChickenBones
Tumbleweed by konwboj
UniDict by WanionCane
Unloader by Unnoen
VoxelMap by MamiyaOtaru
Waila Harvestability by squeek502
WanionLib by WanionCane
Whoosh by Imba_Knugel, EpicSquid319
Wireless Redstone CBE by ChickenBones, covers1624
World Control by xbony2, mincrmatt12, dmf444, The_CodedOne
WrapUp by TheLMiffy1111
ZeroCore by ZeroNoRyouki
Zetta Industries by marcin212a, asiekierka

SpongeForge
griefdefender-sponge-2.1.4
LuckPerms-Sponge-5.3.98

Describe the bug

A plugin i have called GriefDefender listens to block collisions, and sometimes block collisions seem to get called extremely often. Griefdefender checks permissions during a collision, which checks LuckPerms, which needs to get a player's GameProfile instance via Sponge.getServer().getGameProfileManager().get(UUID), which invokes SpongeProfileManager.get(UUID, useCache)

After looking at the source for SpongeProfileManager, i saw that the get(UUID, useCache) method always submits an async task and has to wait for a result. The problem is that block collisions are usually processed on the server thread, which means it obviously halts the server thread until the async executor finishes the task, which in my case causes the server TPS drops to around 2~ TPS. Disabling collision checks in GriefDefender fixed this problem

I'm not sure if block collisions are supposed to be called this often, in which case i've narrowed the issue down to Biomes O' plenty's grass; standing between shortgrass and medium grass (where you collide with both bounding boxes) appears to cause collisions to constantly be fired, causing this huge amount of lag. I'm not really sure if this is entirely a SpongeForge issue, or a GriefDefender/Biomes O' Plenty problem

This is a screenshot of what i captured in VisualVM:

Link to logs

No response

Edit: After recompiling SpongeProfileManager so that submitTask invokes the callable parameter directly, it seems like the server thread is stuck waiting here:

[19:23:34]     at java.net.SocketInputStream.socketRead0(Native Method)
[19:23:34]     at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
[19:23:34]     at java.net.SocketInputStream.read(SocketInputStream.java:171)
[19:23:34]     at java.net.SocketInputStream.read(SocketInputStream.java:141)
[19:23:34]     at sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:464)
[19:23:34]     at sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
[19:23:34]     at sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1341)
[19:23:34]     at sun.security.ssl.SSLSocketImpl.access$300(SSLSocketImpl.java:73)
[19:23:34]     at sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:957)
[19:23:34]     at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
[19:23:34]     at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
[19:23:34]     at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
[19:23:34]     at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:735)
[19:23:34]     at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:678)
[19:23:34]     at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1590)
[19:23:34]     at sun.net.www.protocol.http.HttpURLConnection.access$200(HttpURLConnection.java:92)
[19:23:34]     at sun.net.www.protocol.http.HttpURLConnection$9.run(HttpURLConnection.java:1487)
[19:23:34]     at sun.net.www.protocol.http.HttpURLConnection$9.run(HttpURLConnection.java:1485)
[19:23:34]     at java.security.AccessController.doPrivileged(Native Method)
[19:23:34]     at java.security.AccessController.doPrivilegedWithCombiner(AccessController.java:784)
[19:23:34]     at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1484)
[19:23:34]     at sun.net.www.protocol.https.HttpsURLConnectionImpl.getInputStream(HttpsURLConnectionImpl.java:268)
[19:23:34]     at com.mojang.authlib.HttpAuthenticationService.performGetRequest(HttpAuthenticationService.java:130)
[19:23:34]     at com.mojang.authlib.yggdrasil.YggdrasilAuthenticationService.makeRequest(YggdrasilAuthenticationService.java:66)
[19:23:34]     at com.mojang.authlib.yggdrasil.YggdrasilMinecraftSessionService.fillGameProfile(YggdrasilMinecraftSessionService.java:180)
[19:23:34]     at com.mojang.authlib.yggdrasil.YggdrasilMinecraftSessionService.fillProfileProperties(YggdrasilMinecraftSessionService.java:173)
[19:23:34]     at net.minecraft.server.management.PlayerProfileCache.lookupByIds(SourceFile:667)
[19:23:34]     at net.minecraft.server.management.PlayerProfileCache.getOrLookupByIds(SourceFile:704)
[19:23:34]     at org.spongepowered.common.profile.query.Query.fromUniqueIds(Query.java:71)
[19:23:34]     at org.spongepowered.common.profile.query.UniqueIdQuery$SingleGet.call(UniqueIdQuery.java:64)
[19:23:34]     at org.spongepowered.common.profile.query.UniqueIdQuery$SingleGet.call(UniqueIdQuery.java:45)
[19:23:34]     at org.spongepowered.common.profile.SpongeProfileManager.submitTask(SpongeProfileManager.java:140)
[19:23:34]     at org.spongepowered.common.profile.SpongeProfileManager.get(SpongeProfileManager.java:99)
[19:23:34]     at org.spongepowered.api.profile.GameProfileManager.get(GameProfileManager.java:83)
[19:23:34]     at org.spongepowered.common.service.user.SpongeUserStorageService.get(SpongeUserStorageService.java:55)
[19:23:34]     at com.griefdefender.provider.LuckPermsProvider.getUserSubject(LuckPermsProvider.java:370)
[19:23:34]     at com.griefdefender.provider.LuckPermsProvider.getLuckPermsUser(LuckPermsProvider.java:189)
[19:23:34]     at com.griefdefender.provider.LuckPermsProvider.getLuckPermsHolder(LuckPermsProvider.java:163)
[19:23:34]     at com.griefdefender.provider.LuckPermsProvider.getPermissionValue(LuckPermsProvider.java:1033)
[19:23:34]     at com.griefdefender.util.PermissionUtil.getPermissionValue(PermissionUtil.java:197)
[19:23:34]     at com.griefdefender.permission.GDPermissionManager.getUserPermission(GDPermissionManager.java:496)
[19:23:34]     at com.griefdefender.permission.GDPermissionManager.getFlagOverride(GDPermissionManager.java:618)
[19:23:34]     at com.griefdefender.permission.GDPermissionManager.getFinalPermission(GDPermissionManager.java:394)
[19:23:34]     at com.griefdefender.permission.GDPermissionManager.getFinalPermission(GDPermissionManager.java:247)
[19:23:34]     at com.griefdefender.permission.GDPermissionManager.getFinalPermission(GDPermissionManager.java:224)
[19:23:34]     at com.griefdefender.listener.BlockEventHandler.onBlockBreak(BlockEventHandler.java:845)
[19:23:34]     at org.spongepowered.common.event.listener.BreakListener_BlockEventHandler_onBlockBreak257.handle(Unknown Source)
[19:23:34]     at org.spongepowered.common.event.RegisteredListener.handle(RegisteredListener.java:97)
[19:23:34]     at org.spongepowered.mod.event.SpongeModEventManager.post(SpongeModEventManager.java:383)
[19:23:34]     at org.spongepowered.mod.event.SpongeModEventManager.extendedPost(SpongeModEventManager.java:458)
[19:23:34]     at org.spongepowered.mod.event.SpongeModEventManager.post(SpongeModEventManager.java:419)
[19:23:34]     at org.spongepowered.common.event.SpongeEventManager.post(SpongeEventManager.java:467)
[19:23:34]     at org.spongepowered.common.SpongeImpl.postEvent(SpongeImpl.java:249)
[19:23:34]     at org.spongepowered.common.event.tracking.TrackingUtil.iterateChangeBlockEvents(TrackingUtil.java:567)
[19:23:34]     at org.spongepowered.common.event.tracking.TrackingUtil.processBlockCaptures(TrackingUtil.java:438)
[19:23:34]     at org.spongepowered.common.event.tracking.TrackingUtil.processBlockCaptures(TrackingUtil.java:392)
[19:23:34]     at org.spongepowered.common.event.tracking.phase.packet.player.InteractionPacketState.unwind(InteractionPacketState.java:168)
[19:23:34]     at org.spongepowered.common.event.tracking.phase.packet.player.InteractionPacketState.unwind(InteractionPacketState.java:72)
[19:23:34]     at org.spongepowered.common.event.tracking.PhaseTracker.completePhase(PhaseTracker.java:319)
[19:23:34]     at org.spongepowered.common.event.tracking.PhaseContext.close(PhaseContext.java:618)
[19:23:34]     at org.spongepowered.common.event.tracking.phase.packet.PacketPhaseUtil.onProcessPacket(PacketPhaseUtil.java:221)
[19:23:34]     at net.minecraft.network.PacketThreadUtil$1.redirect$zlf000$impl$redirectToPhaseTracker(SourceFile:540)
[19:23:34]     at net.minecraft.network.PacketThreadUtil$1.run(SourceFile:13)
[19:23:34]     at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[19:23:34]     at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[19:23:34]     at net.minecraft.util.Util.runTask(SourceFile:529)
[19:23:34]     at org.spongepowered.common.SpongeImplHooks.onUtilRunTask(SpongeImplHooks.java:331)
[19:23:34]     at net.minecraft.server.MinecraftServer.redirect$zjj000$onRun(MinecraftServer.java:4682)
[19:23:34]     at net.minecraft.server.MinecraftServer.updateTimeLightAndEntities(MinecraftServer.java:723)
[19:23:34]     at net.minecraft.server.dedicated.DedicatedServer.updateTimeLightAndEntities(DedicatedServer.java:397)
[19:23:34]     at net.minecraft.server.MinecraftServer.tick(MinecraftServer.java:668)
[19:23:34]     at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526)
[19:23:34]     at java.lang.Thread.run(Thread.java:748)

For some reason, the UUID fetch result isn't being cached. And looking at the UniqueIdQuery, after the lookup is complete, if the gameProfiles list returned is empty, it returns i think an empty game profile, but it never caches that UUID as the empty profile, which i assume means that every lookup for that UUID is checked in the mojang database, maybe?

[AngryCarrot789]

I seem to have fixed it by modifying the UniqueIdQuery and Query classes, by changing how it treats returned usernames:

if (this.useCache) {
    String username = SpongeUsernameCache.getLastKnownUsername(this.uniqueId);
    if (username != null || SpongeUsernameCache.containsUUID(this.uniqueId)) {
        return GameProfile.of(this.uniqueId, username);
    }
}

The first time the code runs, the username will be null and the call to containsUUID will return false, causing a lookup. But that will allow the UUID to be cached with a null username, meaning a call to containsUUID returns true

Not sure if this will break sponge in any way, but at least now the server is playable