Rain occurs too infrequently and not randomly
SlimeDog opened this issue · 27 comments
Spigot 1.12.2 latest
EHM 3.12.1
Multiverse-Core 2.6.0-SNAPSHOT-b734
Rain start delay and duration are the maximums of the documented ranges (delay 7.5 MC days, duration 1.0 MC days). Vanilla storms are random (delay 0.5-7.5 MC days, duration 0.5-1.0 MC days).
Please make rain events random, so that players cannot predict when storms will occur or their duration.
What I know, so far:
Define minimal working set
Spigot 1.12.2
EssentialsX-2.0.1-b532
ExtraHardMode-3.12.1
Multiverse-Core-2.6.0-b734
PermissionsEx-1.23.4
ProtocolLib-4.4.0-b390
PyroWeather-1.3.0
Skript-2.2-dev31c
Vault-1.5.6-b49
worldedit-bukkit-6.1.9-b3713
worldguard-legacy-6.2.2-b1710
and full working set
87 plugins, including the minimal working set
PyroWeather is used to manage acid rain. It is configured so that all rain in world_yellowdog is acid rain.
Skript is used only to log the weather events.
With minimal working set, PyroWeather disabled, rain events are random.
[14:12:09] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[14:27:10] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[16:36:03] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[19:16:49] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[21:14:32] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[21:48:40] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[22:45:11] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[01:37:43] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[02:43:43] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[04:46:09] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[06:01:09] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
With Minimal working set, PyroWeather enabled, rain events are random.
[08:21:26] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[09:55:20] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[10:06:29] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[11:01:28] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[11:30:57] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[12:24:10] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[14:00:34] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[14:42:11] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[16:03:46] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[17:46:13] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[20:23:16] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[21:33:14] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
With Full working set, ExtraHardMode disabled, rain events are random, although some are triggered after 2 hours 50 minutes. Note that the documented maximum rain delay is 1 hour 30 minutes (7.5 MC days at 20 minutes per day).
[09:16:02] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[10:14:41] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[12:34:33] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[14:50:31] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[16:17:11] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[16:53:17] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[19:43:11] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[22:33:05] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
With Full working set, all 87 plugins enabled, rain events are not random. Rain is triggered approximately every 2 hours 50 minutes. Each rain event last approximately 20 minutes.
[07:48:58] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[10:38:52] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[13:24:31] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[16:14:25] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[19:04:20] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
[21:54:14] [Server thread/INFO]: [Skript] [start-acid-rain.sk] Weather in world_yellowdog is rain
So, it appears that either ExtraHardMode is affecting the weather event cycle, or some other member of the full working set is interacting with EHM to do so. I will continue testing, removing subsets of plugins to attempt to isolate an interaction culprit.
In the meantime, any other ideas?
I have not been able to isolate this behavior further.
I am working around it with programmed logic to manage weather intervals and durations.
I guess you could try changing some options in the config. I don't have any ideas at the moment either.
Although this is a suggestion, your wording seems to indicate that you think this is a bug? EHM does not currently modify weather events (though it does respond to such changes with certain features).
I could be wrong. I think it is a bug that rain events are not randomly timed, but are always at the maximum of the range. This makes it very easy to predict rain events. The timing and duration are meant to be random; they are random in vanilla worlds. If EHM doesn't modify them, I do not understand how it happens.
If you've tested this, then please report this spigot bug on the spigot bug tracker. (Make sure you test with vanilla spigot and vanilla CraftBukkit, and compare with vanilla.) https://hub.spigotmc.org/jira/projects/SPIGOT/issues
I understand that would help isolate, but it's going to be very difficult, if not impossible. My configuration depends on there being multiple worlds. However, I can significantly reduce the working set. But it has to include Multiverse-Core and Skript (so I can track the weather changes) and a few others. I will do, and report my findings.
Alternatively, if you can provide a debug version of EHM that logs weather events, I could come a lot closer to "just EHM."
I have tested it. The issue occurs only in my ExtraHardMode world. In other worlds, the weather events are random.
As of yesterday, I work around it by generating rain events in my ExtraHardMode world, based on the weather events in other worlds.
only thing I can think of right now is either not much testing/coincidence in current tests or a spigot API bug when checking weather state. I don't see anything in here that modifies weather state, just responses and checks for it.
Yea, didn't say you had to use your production server, a test server will do. As for logging weather events, not sure if any plugin out there does that but you could use eventdebug or similar and just check for weatherchangeevent or w/e it's called.
Ah, well, I'd suggest learning Java and log via just watching the event... but you should at least be able to eliminate Multiverse.
I do all testing on a test server, not on my production server. :)
I can track weather change events with Skript (but that means having Skript enabled, an extra factor).
In any event, I'm making progress collecting data. I'll report findings later, probably tomorrow.
While I have no ideas why the weather intervals happen to be consistent in EHM worlds I've added a debug message in case you or anyone else wants to test this.
FYI, EHM does not modify weather cycles, it merely schedules a torch cleanup task (and snow breaking crops task) for each chunk in the world when the weather changes to rain.
Spigot 1.13.2
EHM 3.13.2-a92e6af
Debug mode confirms that naturally-generated storms in the target world are rarer than expected, but they do occur occasionally -- every 6 IRL hours or so. So I am not sure how to proceed.
I guess this or next weekend I'll spin up some test servers as well. I'll probably also add the world to the debug string
I still can't find anything in this project that would indicate it messing with the weather duration, and the only event handler for WeatherChangeEvent is that torch cleanup task. I wonder if it's any different if torch cleanup was removed; I wonder if loading chunks (in the case they are unloaded by the time the task is scheduled to execute for that chunk) has any effect on weather duration.
Either way, I've added an additional debug message indicating how many tasks were scheduled for torch cleanup (correlates to number of loaded chunks).
As mentioned above, I work around this issue, so I am not actively testing it.
Ran a server with just Paper 1.14.4 and EHM 3.14.0 with debug mode enabled. Here's the log of a single day.
Gist version may be easier to view: https://gist.github.com/RoboMWM/7ed138eee72ff0e13dce96cc973a7613
[01:16:23] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[01:16:23] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[01:16:23] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[01:29:55] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[02:24:35] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[02:24:35] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[02:24:35] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[02:42:54] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[04:35:33] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[04:35:33] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[04:35:33] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[04:49:25] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[05:37:17] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[05:37:17] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[05:37:17] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[05:56:08] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[06:33:48] [Server thread/WARN]: Can't keep up! Is the server overloaded? Running 8765ms or 175 ticks behind
[08:07:20] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[08:07:20] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[08:07:20] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[08:19:27] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[10:43:49] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[10:43:49] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[10:43:49] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[10:58:40] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[11:50:15] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[11:50:15] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[11:50:15] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[12:07:37] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[13:32:51] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[13:32:51] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[13:32:51] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[13:44:17] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[15:51:32] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[15:51:32] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[15:51:32] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[16:08:56] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[16:22:53] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[16:22:53] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[16:22:53] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[16:37:55] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[17:23:10] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[17:23:10] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[17:23:10] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[17:38:19] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[19:06:36] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[19:06:36] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[19:06:36] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[19:25:39] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[21:10:03] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[21:10:03] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[21:10:03] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
[21:27:11] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: false
[23:50:01] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent called. toWeatherState: true
[23:50:01] [Server thread/INFO]: [ExtraHardMode] WeatherChangeEvent says the sky is now falling and will proceed to massacre torches (and exposed crops in snow biomes)
[23:50:01] [Server thread/INFO]: [ExtraHardMode] Scheduled 529 tasks.
I'll probably conduct another test with just a simple plugin listening to weatherchangeevent
10-15 clock minutes
Yes. I'm talking about frequency of storms starting.
assuming you meant to put 150 minutes there then.
Let me recompute -- I may have been mistaken on this entire issue.
1 MC day = 20 clock (ie. IRL) minutes. I calculate from "The average storm lasts 0.5 – 1 day, and there is a 0.5–7.5 day delay between storms" to:
- average storm duration = 0.75 MC day = 15 clock minutes
- average delay before the next storm = 4.0 MC day = 80 clock minutes
It is not clear if "delay between storms" refers to the delay from one storm start to the next, for from one storm end to the next storm start. So depending on which of those is operative, there should be a storm on average every 80-95 clock minutes, lasting an average of 15 clock minutes. That suggests that everything is working correctly with EHM. Apologies for the confusion.
In my ExtraHardMode worlds, I want more frequent and shorter storms. I drive that from a separate input.
According to https://gist.github.com/RoboMWM/7ed138eee72ff0e13dce96cc973a7613#file-diff-separated-csv there doesn't seem to be any recognizable pattern of consistency that I can observe. Varies from 47 minutes to 2 hours 24 minutes.
Sort random, but not frequently enough? Vanilla values are:
- delay 0.5-7.5 MC days = 10-15 clock minutes
sounds about right for maximum amount of time raining (13-18 minutes is the range of being in raining state)