Scary `Created a User for ...` message after switching (?) online-mode

Question

Scary `Created a User for ...` message after switching (?) online-mode

molor opened this issue 2 years ago · 20 comments

molor commented 2 years ago

Type of bug

Compatibility issue, Other unexpected behaviour

`/ess dump all` output

https://essentialsx.net/dump.html?id=573389f7f074432f91e0c94d0b669bc5

Error log (if applicable)

[11:56:06 INFO]: [Essentials] Created a User for CanadaLt (a7f82311-4c32-341b-b28b-118afafdbe49) for non Bukkit type: org.bukkit.craftbukkit.v1_18_R2.entity.CraftPlayer
java.lang.Throwable: null
        at com.earth2me.essentials.userstorage.ModernUserMap.debugLogUncachedNonPlayer(ModernUserMap.java:203) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at com.earth2me.essentials.userstorage.ModernUserMap.loadUncachedUser(ModernUserMap.java:131) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at com.earth2me.essentials.Essentials.getUser(Essentials.java:1076) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at com.earth2me.essentials.EssentialsPlayerListener$CommandSendFilter.apply(EssentialsPlayerListener.java:1006) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at com.earth2me.essentials.EssentialsPlayerListener$CommandSendFilter.apply(EssentialsPlayerListener.java:1003) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at net.ess3.provider.CommandSendListenerProvider.filter(CommandSendListenerProvider.java:22) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at net.ess3.provider.providers.PaperCommandSendListenerProvider.onAsyncCommandSend(PaperCommandSendListenerProvider.java:26) ~[EssentialsX-2.20.0-dev+39-312d169.jar:?]
        at com.destroystokyo.paper.event.executor.asm.generated.GeneratedEventExecutor20.execute(Unknown Source) ~[?:?]
        at org.bukkit.plugin.EventExecutor.lambda$create$1(EventExecutor.java:75) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at co.aikar.timings.TimedEventExecutor.execute(TimedEventExecutor.java:76) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:git-Paper-387]
        at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:70) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:669) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at org.bukkit.event.Event.callEvent(Event.java:45) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at net.minecraft.commands.Commands.sendAsync(Commands.java:387) ~[?:?]
        at net.minecraft.commands.Commands.sendCommands(Commands.java:364) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
        at java.lang.Thread.run(Thread.java:833) ~[?:?]

Bug description

After switch from online mode to offline (for testing some things on local server hardware w/o internet access in my case), if player previously connected during online mode, I get the message mentioned above in the logs.

Steps to reproduce

Start up the server jar w/ Essentials, EssentialsSpawn and EssentialsGeoIP (the latter is probably not necessary but in my case I have it) in plugins/ folder and eula=true in eula.txt file
Connect to it
Disconnect from it
Stop the server
Change online-mode from true to false in server.properties
Start the server again
Connect to it
See the Created a User for ... in logs

My startup flags, if it is necessary or makes sense: java -Xms1G -Xmx2G -XX:+UseG1GC -XX:+ParallelRefProcEnabled -XX:MaxGCPauseMillis=200 -XX:+UnlockExperimentalVMOptions -XX:+DisableExplicitGC -XX:+AlwaysPreTouch -XX:G1NewSizePercent=30 -XX:G1MaxNewSizePercent=40 -XX:G1HeapRegionSize=8M -XX:G1ReservePercent=20 -XX:G1HeapWastePercent=5 -XX:G1MixedGCCountTarget=4 -XX:InitiatingHeapOccupancyPercent=15 -XX:G1MixedGCLiveThresholdPercent=90 -XX:G1RSetUpdatingPauseTimePercent=5 -XX:SurvivorRatio=32 -XX:+PerfDisableSharedMem -XX:MaxTenuringThreshold=1 -Dfile.encoding="utf-8" -Dnet.essentialsx.usermap.print-stack=true -jar "server.jar" nogui

Expected behaviour

No Created a User for ... message.

Actual behaviour

See Bug description.

molor · Answer 1 · 2023-01-08T15:31:31.000Z

Happy NY, but bump :/

molor · Answer 2 · 2023-01-12T20:20:26.000Z

No, in my case it's just placed in different directory via log4j configuration file.

But why you closed this "as completed" and nothing was changed it the code?.. :c

JRoy · Answer 3 · 2023-01-12T17:09:10.000Z

You excluded the log from the dump for some reason? I'm going to need a full dump with this error present in the logs for me to look into this at all. I'll reopen if you reply with one.

mdcfe · Answer 4 · 2023-01-12T21:13:33.000Z

"closed as completed" is the default GitHub message when closing an issue.

Please provide a dump with the log included. You will need to temporarily revert your log4j config changes for /ess dump to attach your log.

molor · Answer 5 · 2023-01-13T08:43:06.000Z

It's a log file from this issue, maybe that will be enough: https://paste.gg/p/anonymous/746b6010ed394ffda1d6b701933e6a8e

molor · Answer 6 · 2023-01-14T21:00:37.000Z

So the only way for me get rid of this annoying message to use a log4j filter?
Issues section of this plugin seems to be useless

mdcfe · Answer 7 · 2023-01-14T21:04:35.000Z

Please provide a dump with the log file included. This error is not normal and should not be filtered out.

JRoy · Answer 8 · 2023-01-14T21:04:57.000Z

So the only way for me get rid of this annoying message to use a log4j filter? Issues section of this plugin seems to be useless

You aren't paying for 24/7 response time support nor do we offer it. The issue section of this plugin isn't useless, we just are busy doing things in the real world.

molor · Answer 9 · 2023-01-14T21:25:39.000Z

I'm noticed that it appears mostly after I switch it to local/offline from online mode to test some things w/o internet access
https://essentialsx.net/dump.html?id=3ce9167364654bfaa1733f3689440124

molor · Answer 10 · 2023-01-14T21:28:10.000Z

And every time I'm connecting to the server for the first time, Essentials logs that message

pop4959 · Answer 11 · 2023-01-14T21:37:30.000Z

Can you replicate this on a fresh server, for example with switching online/offline as you mentioned?

molor · Answer 12 · 2023-01-14T21:40:33.000Z

Yes, this is already a fresh server w/o any other plugins and with default settings. If you can't replicate this and need to test something on my side, tell me

pop4959 · Answer 13 · 2023-01-14T21:48:54.000Z

Yes, this is already a fresh server w/o any other plugins and with default settings. If you can't replicate this and need to test something on my side, tell me

That's why I asked, this isn't reproducible on a fresh server with the steps you provided.

Following log from an entirely fresh server running Paper-378.

[13:42:19 INFO]: Done (3.883s)! For help, type "help"
[13:42:19 INFO]: Timings Reset
[13:42:19 INFO]: [Essentials] Fetching version information...
[13:42:28 INFO]: UUID of player pop4959 is a806bad6-4b60-47dd-8048-6a4945125726
[13:42:28 INFO]: pop4959 joined the game
[13:42:28 INFO]: pop4959[/127.0.0.1:54314] logged in with entity id 320 at ([world]8.5, 49.0, 3.5)
[13:42:28 WARN]: [Essentials] File motd.txt does not exist. Creating one for you.
[13:42:31 INFO]: pop4959 lost connection: Disconnected
[13:42:31 INFO]: pop4959 left the game
[13:42:32 INFO]: UUID of player pop4959 is a806bad6-4b60-47dd-8048-6a4945125726
[13:42:32 INFO]: pop4959 joined the game
[13:42:32 INFO]: pop4959[/127.0.0.1:54321] logged in with entity id 485 at ([world]8.5, 49.0, 3.5)
> pl
[13:43:44 INFO]: Plugins (1): Essentials
> ver Essentials
[13:43:47 INFO]: Essentials version 2.20.0-dev+39-312d169
[13:43:47 INFO]: Provides an essential, core set of commands for Bukkit.
[13:43:47 INFO]: Website: https://essentialsx.net/
[13:43:47 INFO]: Authors: Zenexer, ementalo, Aelux, Brettflan, KimKandor, snowleo, ceulemans, Xeology, KHobbits, md_5, Iaccidentally, drtshock, vemacs, SupaHam, mdcfe, JRoy and pop4959

If you are still able to produce this issue, please provide updated reproduction steps.

molor · Answer 14 · 2023-01-14T21:52:19.000Z

OK, I'll provide it a little bit later, left home for now.

molor · Answer 15 · 2023-01-15T09:02:49.000Z

Updated the issue, please review @pop4959

molor · Answer 16 · 2023-01-20T14:17:31.000Z

I'll reopen if you reply with one.

@JRoy

molor · Answer 17 · 2023-01-21T21:59:58.000Z

Well.. Is there any other way I can help with solving this issue? If you need to test something on my side, tell me

pop4959 · Answer 18 · 2023-01-21T21:37:48.000Z

I am still not able to reproduce your issue after following the updated steps.

pop4959 · Answer 19 · 2023-01-21T22:03:51.000Z

Well.. Is there any other way I can help with solving this issue? If you need to test something on my side, tell me

It helps if you provide reproducible steps. Look through and confirm that what you have is valid, using the latest versions, or otherwise adjusting your steps with other pertinent information.

molor · Answer 20 · 2023-01-22T06:36:45.000Z

~~Maybe I can upload my server folder to some cloud storage site and you try to reproduce on it? If so, give me a site URL please.~~
~~If you can't reproduce using it too, maybe it's platform-related issue..~~

Well, I'm used a log4j filter, it's faster than waiting for a response from you, and even faster than waiting for a fix (2+ months passed :/), so don't waste your time to answer..

Share to