SpongePowered / Sponge

The SpongeAPI implementation targeting vanilla Minecraft and 3rd party platforms.
MIT License
389 stars 211 forks source link

Frequent crashes caused by "User {} is not initialized" #2596

Closed Shmeeb closed 4 years ago

Shmeeb commented 4 years ago

I am currently running Minecraft: 1.12.2 SpongeAPI: 7.2-fe189dcf Sponge: 1.12.2-7.2.0 SpongeForge: 1.12.2-2838-7.2.0 Minecraft Forge: 14.23.5.2838

Plugins (106): Minecraft, Minecraft Coder Pack, SpongeAPI, Sponge,  FastAsyncWorldEdit, ActiveTime, AdminShopEC, AdventureMMO, AnimationPlugin, ArenaControl, ArmorStandTools, AutoMessageEC, AutoRestarterEC, AwayFromSpawns, BiomeRTP, BossBar, BossPackages, ChangeLogNotifier, ChatColors, ChatShow, ChestShop, ClaimTweaks, ClearMob, CoinFlip, CommandNPCSEC, CommandSigns, CommandUtils, Cosmetics, CrateKeys, CustomSpawners, DiscordIntegration, DropCratesEC, EconomyLite, Emotes, Enjin Minecraft Plugin, EufranioUtils, Even More Pixelmon Commands, Fireworks, ForumScraper, FoxCore, FoxGuard, FullBrightEC, GTS, GTS Reforged Bridge, GamblingEC, GriefPrevention, GuildsEC, HelpMe, Holograms, HuskyCrates, HuskyUI, ImpactorAPI, ItemTradeEC, JdaLibraryLoader, KitSuiteEC, LeaderHeads, Lightshow, LuckPerms, MagiBridge, MiscEC, MobClear, Mod Patcher, NexusEC, Nickname Manager, NuVotifier, Nucleus, PacketGate, Personal Time, PixelGyms, Pixelmon Wiki Gui, PixelmonOverlay, PixelmonPlaceholders, PlaceholderAPI, Player vaults, PlayerQueueService, PokeBuilder, PokeColor, PokeDisguise, PokeHuntsEC, PokeParticlesSponge, PresentsEC, Prism, ProjectCore for SpongeAPI 7.x, ProjectPortals, RandomCommandsEC, SchematicSyncerEC, ServerListPlus, SignEditor, SpongyHolograms, StatueControlEC, TabManager, TeslaCore, TeslaLibs, TitlesEC, TriviaQuest, UltimateChat, View-sponge, VirtualChest, VoteSuite, VoxelSniper, WorldEdit, YourCustomPaintings, acorpSTS, builderplugin, midi-player, spark

Mods (19): Minecraft, Minecraft Coder Pack, Forge Mod Loader, Minecraft Forge, SpongeAPI, Sponge, Capturedupefix, Emotes, Fzzy Quests, LegendaryPlus, MiscECMCF, MoveSkillController, PhioneBePhigone, Pixel Extras, PixelEvent, Pixelmon, Pixelmon Trainer Commands, SpongeForge, Wondertrade

https://pastebin.com/bdwePtR2

I've been getting this crash semi frequently: User {} is not initialized [2fca8a56-87ae-48f9-8ea8-87374288bdae]

My staff banned that player ^ about 30 mins before the server crashed, and they were /invsee'd 10 mins before, thats all

Another crash I found on google: https://pastebin.com/rjMi1Bps

gabizou commented 4 years ago

Could you provide some steps to reproduce? I can only imagine that a user is being marked as dirty, but setting up a server with 106 plugins and 19 mods is not a minimum setup required to understand the root of the problem. It may be possible to provide some debugging information to the user when it was created, but knowing how it gets created in the first place is one of the troubles I have understanding this problem.

dualspiral commented 4 years ago

No response in nearly three weeks, closing.

AustinOveraitis commented 4 years ago

https://paste.acorp.tech/?2df2bd1ebce64f3f#3eyxAfnUUgQ35PXbr1MTbctNzdHQ18AiTESqWAQZatY9

We also experienced this crash, as noted above.

My developer noted the following:

This might need to be reported to sponge. The basic gist is that Sponge will save users with this class https://github.com/SpongePowered/SpongeCommon/blob/stable-7/src/main/java/org/spongepowered/common/entity/player/SpongeUser.java. Sponge uses guavas Preconditions class to handle a lot like null checks, argument checks, etc. One of these checks that seem to be invoked here is a state check. Meaning its checking if the object is still there before doing what it needs to. In this instance, the thing it wanted to do was save player NBT data to the file. Why the check failed is because the user was no longer saved in memory.

Were any jar arguments changed in the last day or so? Additionally, is the ram doing alright rn? Like not having too many servers running and what not Preconditions.checkState(isInitialized(), "User {} is not initialized", this.profile.getId()); Looking here

would report that. Little out of my pay grade to fix that lol

public boolean isInitialized() {
    return this.nbt != null;
}

is returning false for this guy https://mcuuid.net/?q=52907da9-d941-4c9a-aff0-4e6413a30c52

Shmeeb commented 4 years ago

Just checked my logs and I'm getting this fairly often on 2/5 servers only, this one is the worst: https://gyazo.com/78ca26b306801192c551533a992313d5

Latest one was caused by UUID 46a9ddd5-c15c-4d8c-a62f-b03b06089563 and username Aegard_

If you review this log https://pastebin.com/JRNJn5G6 you can see that the user joined at 10:06 and was banned at 10:36 and the server crashed at 11:31. I believe this was caused by my staff /invsee ing them at 11:21

Shmeeb commented 4 years ago

Sorry for the delay @gabizou @dualspiral could you re-open this please

Shmeeb commented 4 years ago

My auto save settings: auto-save-interval=12000 auto-player-save-interval=12000

[11:21:16] [Server thread/INFO] [nucleus]: Solair_The_Sun ran the command: /invsee aegard_
[11:31:25] [Server thread/ERROR] [net.minecraft.server.MinecraftServer]: Encountered an unexpected exception

Seems too close to 10 mins to be a coincidence (same thing in my initial pastebin)

LXGaming commented 4 years ago

Environment:

Reproduce:

  1. Run /invsee <Offline Player> in-game.
  2. Modify the inventory (Make sure you keep the inventory open).
  3. Run /save-all from console.
  4. Modify the inventory again.
  5. Run /save-all from console or wait for auto save.

What's happening?:

  1. /invsee causes the SpongeUser to be initialized.
  2. Modifying the inventory causes the SpongeUser to be marked as dirty.
  3. All dirty SpongeUsers are saved and invalidated.
  4. Modifying the inventory causes the invalid SpongeUser to be marked as dirty.
  5. The server attempts to save the invalid SpongeUser.
dualspiral commented 4 years ago

So, really, there are two problems here:

I'm guessing what happened to those of you who got this error is that you used /invsee just before a save-all happened - in @Shmeeb's case, 11 seconds before - so this would make a lot of sense.

We'd need to make sure initialised but not dirty users don't drop out of the cache too.