[GEN][ZH] Fix Mismatch in Release Build when Logging is enabled

[helmutbuhler]

This PR disables some logging in Releasebuild when Logging is enabled that causes a Mismatch. It'll be nice to have logging work in release builds to debug mismatch issues.

With this fix applied, you can load a retail replay with AI players and play it back in a Release build with logging without mismatches.

[xezon]

This is wild. The log is not modifying anything. Is this perhaps related to compiler optimizations that the added logging will affect?

[helmutbuhler]

Yes, sin and cos are internally implemented with doubles. If the logging is not there, the optimizer removes the casts to float and uses the doubles in the final calculation. If the logging is there, it doesn't remove the cast because the float is logged, and then also uses the float in the gamelogic.
This happens in quite a few places, but luckily only this log call seems to cause a gamelogic change.

[xezon]

This is outrageous lol. Nice. Can this perhaps also be fixed by moving the logging a few lines?

[helmutbuhler]

I highly doubt it. Also keep in mind that some other log calls are already guarded by #if defined(_DEBUG) || defined(_INTERNAL). One of them in the same file. The original devs were possibly aware of this issue and just missed this one Log call.

[roossienb]

Does this mean that after the fix, the debug version of the game mismatches against the release version of the game? That could hamper testing efforts. Or does it mismatch already?

[helmutbuhler]

Yes, VC6 Debug and Internal Version immediately mismatch against retail. Fixing that would be very difficult. I initially planned to do that and published that work here: #540
But it's so much work, it's not really feaseble.

[xezon]

I tested this change with replay of https://github.com/roossienb/GeneralsWiki/blob/e52ca6618f90cef9ece00cbb7abacc293f580b12/SourceCode/Debug/files/Zerohour-skirmish.zip and it mismatched with vs6 release build + RTS_DEBUG_LOGGING=ON + RTS_DEBUG_CRASHING=ON. Did I do something wrong?

[helmutbuhler]

I tested this change with replay of https://github.com/roossienb/GeneralsWiki/blob/e52ca6618f90cef9ece00cbb7abacc293f580b12/SourceCode/Debug/files/Zerohour-skirmish.zip and it mismatched with vs6 release build + RTS_DEBUG_LOGGING=ON + RTS_DEBUG_CRASHING=ON. Did I do something wrong?

Thanks for testing! You are right, looks like there is something else that causes mismatches. I'll try to find that issue as well. It's a bummer though because it's really annoying to find these things. Took me almost an entire day to find this one in this PR.

Btw I used the attached replay for this PR, in case you wanna check. Someone on Discord provided it.
tansooo.zip
TANSO AI 1v1 GLA Mirror.zip

[helmutbuhler]

I tested this change with replay of https://github.com/roossienb/GeneralsWiki/blob/e52ca6618f90cef9ece00cbb7abacc293f580b12/SourceCode/Debug/files/Zerohour-skirmish.zip and it mismatched with vs6 release build + RTS_DEBUG_LOGGING=ON + RTS_DEBUG_CRASHING=ON. Did I do something wrong?

Just pushed a fix for it. This time it's likely different code due to different inlining.

[xezon]

How do you come to the conclusion that these logs cause mismatch in particular?

[xezon]

https://github.com/user-attachments/files/19917484/TANSO.AI.1v1.GLA.Mirror.zip

This replay cannot be used because the map is unknown.

[xezon]

I tested this updated change against https://github.com/roossienb/GeneralsWiki/blob/e52ca6618f90cef9ece00cbb7abacc293f580b12/SourceCode/Debug/files/Zerohour-skirmish.zip and it still mismatches.

Edit: The above replay also goes out of sync without Release logging. Perhaps that replay is bad?

How do you determine what logging would be mismatching?

[roossienb]

I tested this updated change against https://github.com/roossienb/GeneralsWiki/blob/e52ca6618f90cef9ece00cbb7abacc293f580b12/SourceCode/Debug/files/Zerohour-skirmish.zip and it still mismatches.

Edit: The above replay also goes out of sync without Release logging. Perhaps that replay is bad?

How do you determine what logging would be mismatching?

I just tested the replay against the latest MAIN build and have no mismatches.

[helmutbuhler]

How do you determine what logging would be mismatching?

I basically do a binary search over the cpp files. I disable the DEBUG_LOG macro in individual files and pin point to the file, then to the log call.

[xezon]

I basically do a binary search over the cpp files. I disable the DEBUG_LOG macro in individual files and pin point to the file, then to the log call.

Uff that is tough. I was hoping that the CRC logging would help pinpointing it.

[helmutbuhler]

I basically do a binary search over the cpp files. I disable the DEBUG_LOG macro in individual files and pin point to the file, then to the log call.

Uff that is tough. I was hoping that the CRC logging would help pinpointing it.

CRC logging can also cause mismatches ;) The problem isn't that something is written to disk, but that the optimizer produces different machinecode.

[xezon]

I was unable to confirm that this change fixes mismatching when logging is enabled. But we can go ahead and merge it I guess.

[helmutbuhler]

Alright, I did some extensive testing and found a few more Log calls that caused mismatches. I put 4 more #ifdefs around some log calls. I also fixed a runtime error when the version string that is stored in the replay has some russian characters.

With these changes, I could successfully simulate 1400 replays that were uploaded on the Gentool server without mismatches, so I feel pretty confident that logging doesn't cause any false mismatches anymore. But of course there is no 100% guarantee.
I also made sure that DEBUG_LOGGING and DEBUG_CRASHING works, initially I only enabled DEBUG_LOGGING.

I also found out that the log in StateMachine::internalGetState only causes mismatches when the supplyTruck variable is kept uninitialized. So I also checked if initializing that variable causes any mismatches, and it doesn't. So my suggestion is to initialize that variable (I'll make a PR) and we can keep the logging here in Release mode (I took the #ifdefs out)

I attach here 3 replays that will cause mismatches in Release with DEBUG_LOGGING and DEBUG_CRASHING defined and this PR not applied. Each of the 3 files where I added #ifdefs fixes one of the replays.
release_logging_desyncs.zip

[helmutbuhler]

So can this be merged now?