JIP breaks nextWeatherChange values resulting in unsynced weather.
Closed, ResolvedPublic
Actions

Description

When a player JIPs into a running game the nextWeatherChange value on the server (and client) breaks.

If the nextWeatherChange values don't match or change from the specified by setovercast then the rate at which the overcast value changes on clients will differ too resulting in unsynced weather.

Another small observation.
Also noticed that if the clientside window loses focus or the fullscreen is tabbed out then because client simulation stops and the overcast value pauses and does not catch up with the server once focus is restored...

SERVER RPT:

Client JIPs in here!

CLIENT RPT:
BEFORE PLAYER EXITS:

CLIENT RPT:
WHEN PLAYER JIPS:

"Time: 0 | Locality: CLIENT | Overcast: 0.3 | nextWeatherChange: 1800"
Weather was forced to change
"Time: 400.386 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1799.52"
"Time: 401.401 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1798.46"
"Time: 402.415 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1797.46"
"Time: 403.427 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1796.45"
"Time: 404.443 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1795.45"
"Time: 405.443 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1794.47"
"Time: 406.454 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1793.46"
"Time: 407.469 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1792.46"
"Time: 408.481 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 4.13167"
"Time: 409.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3.147"
"Time: 410.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 2.147"
"Time: 411.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 1.147"
"Time: 412.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 0.146992"
"Time: 413.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3186.98"
"Time: 414.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3185.98"
"Time: 415.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3184.98"
"Time: 416.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3183.98"
"Time: 417.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3182.98"
"Time: 418.506 | Locality: CLIENT | Overcast: 0.860021 | nextWeatherChange: 3181.98"
{F23581} {F23582} {F23583}

Details

Legacy ID: 1349229791
Severity: None
Resolution: Not A Bug
Reproducibility: Sometimes
Category: Engine

Steps To Reproduce

Repo mission attached.

Run it on a dedicated server with persistent=1; in server.cfg.

The missions default overcast value is 0.

The mission will wait 15 seconds before applying setovercast to 1 on server using new new engine command forceWeatherChange.

The mission will then wait 15 seconds for forceWeatherChange to propagate to the client.

Success!

The mission will then wait 15 seconds and then set a new overcast value of 0.3 over 30 minutes.

Now disconnect right out of the lobby and JIP your client back into the game and watch the server and clients RPTs...

Additional Information

Type: Public
Branch: Stable
Version: 1.14.116248

Event Timeline

Bohemia added a project: Arma 3.May 7 2016, 6:16 PM

Jman edited Steps To Reproduce. (Show Details)Mar 26 2014, 2:20 PM

Jman edited Additional Information. (Show Details)

Jman set Category to Engine.

Jman set Reproducibility to Sometimes.

Jman set Severity to None.

Jman set Resolution to Not A Bug.

Jman set Legacy ID to 1349229791.May 7 2016, 6:16 PM

Bohemia added subscribers: Dwarden, Fireball, ViperMaul and 2 others.Mar 26 2014, 2:20 PM

AD2001 added a subscriber: AD2001.May 7 2016, 6:16 PM

Is this reproducible on the dev branch?

Killzone_Kid added a subscriber: Killzone_Kid.May 7 2016, 6:16 PM

Cannot reproduce it on dev branch. Also I'm not happy about my client freezing for a second after I execute forceWeatherChange on the server.

Setting to (already) resolved then.

Freezing the client for a second on weather change should be its own ticket, but they're probably aware of the issue.

Would be nice to hear confirmation from another tester on dev branch.

Just tested on Server and client versions of:

Type: Public
Branch: Development
Version: 1.15.116294

Same issue exists. RPT below:

SERVER RPT:

Client JIPs in here!

CLIENT RPT
BEFORE PLAYER EXISTS:

CLIENT RPT:
WHEN PLAYER JIPS:

Still can't reproduce:

must be JIP here

Show me where the Client Jips in your rpt. I'm not seeing it?

@Jman They are (one) somewhere there, towards the end on server rpt, on client no idea, since you haven't provided a function to log them. I just ran your script as is.

EDIT I added client part that I missed because of long rpt

Finally, I've found the issue. It's not the engine it's cba that breaks the weather sync values.

Please compare these two rpt archives:

http://www.kellys-heroes.eu/files/arma3/rpt/Weather_Test_RPT_no_cba.7z
http://www.kellys-heroes.eu/files/arma3/rpt/Weather_Test_RPT_with_cba.7z

http://dev.withsix.com/issues/74300

Geez. Why can't people just test vanilla...waiting with resolved until we're sure there's no engine involvement to this issue.

Xeno added a subscriber: Xeno.May 7 2016, 6:17 PM

Nothing to do with CBA, one can easily reproduce it without using any addons. It's just not reproducable with a simple test mission.

what xeno said ^ ive also observed that without CBA

we are out, sorry! if you think its fine and fixed, Fireball, so be it! Im sure we could provide a repro that is even more clear about it, but we don't have the time to invest more hours on testing that issue, than the several hours our team invested already. We were just wanting to help!

In any case Reproducibility needs to be changed from "always" to "sometimes"

Keep your head high, highhead. There seems to be an issue and you're probably not the only guy(s) interested in a fix, the the CBA team is looking into it anyway.

Once we have a reliable repro, BI devs can have a look. Maybe there is no reliable repro, but 'we' get it to reproduce without any mods and then we know it might be a racing condition within the engine (which would be my guess).

Killswitch added a subscriber: Killswitch.May 7 2016, 6:17 PM

CBA team here. There actually is (now: was) an issue with CBA where an old weather sync system that was supposedly disabled for ArmA III was not quite fully disabled. This caused the rather abrupt change in the nextWeatherChange value on the server as seen in Jman's server log excerpt above at around 218.322 where nextWeatherChange goes from 1732 to 4. We have fixed that problem for an upcoming update of CBA for ArmA III.

With that out of the way, the "weather divergence" between server and client can be observed even with a vanilla, no-mods A3 setup. However, the difference in weather change values is not as abrupt. (You can actually see it in Killzone_Kid's logs above.) There's more on this if you look at ViperMaul's comments for the CBA issue here: https://dev.withsix.com/issues/74300#note-7

Divergences are made by way of synchronization. We cannot set weather values immediately because this would cause lag (as in case of forceweatherchange). This lag is there because of external library SimulWeather (we need to force him to recalculate some quite complex stuff and it takes him a long time). So instead of it we are going in way of slowly changing weather according to current state on server. In fact state of weather on server is setted as target state on client so client will over time end on more or less same values therefore same weather ;-)

@sadovsf I think what he means is why when I JIP nextWeatherChange does not get synced immediately to the server value upon joining?

Joining as JIP:

quite a bit of difference in nextWeatherChange on client that just joined and on server ^^^

nextWeatherChange slightly depends on external library (SimulWeather) so it is little bit different on different PCs and if you look on it Time is also little bit different

TimeDif: ~+0.6
nextWeatherChangeDif: ~+60

So difference is the same as difference in time so in fact it is same. It have same absolute time. Overcast is also little bit different because we are interpolating and in fact chasing server state. If i will simply set server state to client it will result in Lags

"So difference is the same as difference in time so in fact it is same"

The difference in nextWeatherChange is 1 minute
The difference in time frame is 0.6 second

I'd say there is about 100 times difference :)

After CBA team took their time to investigate the issue, i also pulled my head out and gave it another go...

To start with the positive news...
"When a player JIPs into a running game the nextWeatherChange value on the server"
--> Thanks to the CBA team, this seems fixed with the hotfix! Awesome, how quickly you could determine and resolve the issue!

Still, weather sync is not handled correctly by the engine - and this was replicable three times in a row with all the information already provided in this ticket on Vanilla A3 stable (so not related to CBA in any way).

Still Nextweatherchange isnt in sync, resulting in the exact same behaviours (unsync weather for all clients). If its intended to slowly sync weather independendly on clients, then it just goes wrong.

You can find server.rpt (dedi) and client.rpt attached. You can also see it in KKs rpt.

Highlights...

Weather starts off synced after mission start:

Weather was forced to change
"Time: 16.058 | Locality: SERVER | Overcast: 1 | nextWeatherChange: 1783.96"

"Time: 17.12 | Locality: CLIENT | Overcast: 1 | nextWeatherChange: 1782.95"

After 5 minutes of beeing connected (before JIP), server and client are not synced anymore (see overcast value):

"Time: 438.223 | Locality: SERVER | Overcast: 0.844491 | nextWeatherChange: 1361.87"

"Time: 438.554 | Locality: CLIENT | Overcast: 0.990919 | nextWeatherChange: 1361.24"

After JIP, clients sync weather back from server, means that every JIP player will have a different weather (because of the issue above):

"Time: 458.296 | Locality: SERVER | Overcast: 0.836713 | nextWeatherChange: 1341.81"

"Time: 458.196 | Locality: CLIENT | Overcast: 0.837593 | nextWeatherChange: 1799.23"

And after 20 minutes of beeing connected its out of sync completely, esp. new clients that just JIPed (that were just synced) vs. connected clients.

connected players: http://imgur.com/gqwImP9&qS85fR1#0

freshly joined players: http://imgur.com/gqwImP9&qS85fR1#1

Wind direction changed from varying between 0-30deg at start to 330-360 degrees at the end of my test (about 25 mins)!
I havent tested if wind was synced.

PS: corrected some spelling mistakes and made some parts clearer (hopefully, my english is not the best)

Please advice on how you would like it to have:

Do you want me to log a seperate ticket for unsync weather and close this, because the specific issue "When a player JIPs into a running game the nextWeatherChange value on the server (and client) breaks" is solved due to the CBA hotfix?

Do you want to refer to ticket ID 14296 (http://feedback.arma3.com/view.php?id=14296 ), where more or less those issues are also noted but in a different relationship (local vs. global) and close this one?

Do you want to stick with this ticket and update it?

the nextWeatherChange is all over the place in the last build. client 0.65 server 22288 after JIP, something like that.

KK opened a seperate ticket here http://feedback.arma3.com/view.php?id=18237

Closing down this one then. Thanks highhead!

JIP breaks nextWeatherChange values resulting in unsynced weather.Closed, ResolvedPublicActions