[Wine] Inputs are not processed deterministically

[clementgallet]

Tested on Dustforce DX, but it should be relevant for a lot of games.

Playing back a movie does not always end up with the same behavior. Some inputs are dropped. Sometimes a key is still considered held even if released in the movie (e.g. the character is constantly moving to the right).

Input events are queried inside X11DRV_MsgWaitForMultipleObjectsEx(), which is called from a different thread as the rendering thread, which is problematic. libTAS option Asynchronous events doesn't work because it waits for the event queue to be empty. However, wine is querying events using XCheckIfEvent(), which only pulls events that pass the function predicate, so the event queue may never be empty.

[InfamousKnight]

Testing midnight club 2, and inputs desync after loading a map. The loading times vary, and if it loads too soon, the inputs don't really match either way. Some inputs are dropped, like when turning right.

To run it, go to Debug, Time tracking all threads, clockgettime and sdl-getticks.

When I printed the File IO log, this showed up many times: [libTAS f:6] Thread 1932 (main) Unknown file descriptor 49 1[libTAS f:6] Thread 1932 (main) dup call on 16 [libTAS f:6] Thread 1932 (main) new fd: 49 [libTAS f:6] Thread 1932 (main) close call

And checking Xevent under async, this shows up each time an input is made:

[libTAS f:15] Thread 2051 (main) ERROR: xevents sync took too long, were asynchronous events incorrectly enabled?

tested on commit ce77077

[clementgallet]

It is not the same issue. Options under Debug menu are meant for debugging, they break determinism. The issue is already described in #242

[InfamousKnight]

Oh, now I understand. Sorry.

[clementgallet]

Inputs are also processed by wine server it seems... Xlib events are handled by X11DRV_KeyEvent() -> X11DRV_send_keyboard_input() (both winex11.drv/keyboard.c) -> __wine_send_input() (user32/input.c) -> send_hardware_message() (user32/message.c), which sends the key event to the server, and optionally waits for the reply.

So currently we may have delays in inputs event handling because the server might generate an input message too late? I'm not familiar with Windows API.

@madewokherd any idea on a good way to solve this? Could we ensure the communication with the server in synchronous in case of inputs? Or maybe we could hook some Windows API functions like GetAsyncKeyState() and the message queue?

Also, by looking at wine's GetAsyncKeyState() implementation, it is using a cached value if the previous key query was done less than 50 (ms?) ago, which doesn't look good for frame-precise inputs?

[madewokherd]

I don't think it's good to rely on the inputs making their way to things like GetMessage because the inputs could be diverted or reported another way.

Communication with the server is always synchronous, in that the server has processed the request (whatever that means) when wine_server_call completes.

It looks like the "wait" in send_hardware_message tells us if there are any low-level hooks (which may go to another process) that the message has to go through before it gets to an event queue. I think the intent is that when __wine_send_input returns, the message has already gone through any low-level hooks, and it has either been added to a queue or dropped. Any message-related calls made on the appropriate thread after that would be able to see the event.

It's hard to propose an exact solution because I'm not sure of your requirements. Is it enough to know that the game can see the input messages and assume it will process them before it blocks?

I'm really surprised about GetAsyncKeyState. If games rely on this, and they don't have any low-level keyboard hooks (which reset global_key_state_counter), that would cause some major input lag.

[InfamousKnight]

Input determinism in midnight club 2 are pretty decent. Loading screens are consistent and fast and the inputs for the most part sync. All the inputs at the beginning sync, but near the end of a 30 second test movie, it has a sleight desync. Like I hit a person in making the movie, but playing it back hits a car instead around the same area. Playing it back multiple times, gives the same result.

[Edit] Its actually not that great still. Inputs are still dropped, keys are still considered held at times, etc. But loading times are consistent.

[InfamousKnight]

Further testing, midnight club 2 runs at 30fps, and if I checked xevent, the loading screens take long, are very inconsistent, and inputs still drop either way. If I turn off xevent, the loading screens are more consistent(as in, no large gaps in between like when xevent was checked).

So when making the movie, the loading of the map stops at frame 622, when playing it back, it either stops at 620, 623, 621 when xevent is turned off. When turned on, those gaps are much larger. And if the map starts sooner, you'd think the inputs would sync, but they dont. Seems to help if you go in a straight line without turning until the 4th delay comes up, and then turn. But still, kinda random.

Has anyone had any success with other wine games?

[ghost]

Here to tell you than i successfully TASed a windows games without desync. Good Job. Regression since d41cb94 (totally desync). In deb1fe9 if i disable sound (pulse used by default) in wine i have no desync in THUG Pro (tony hawk underground 2 mod).

[InfamousKnight]

Nice to hear a solution was found! Now we just have to figure out a way to get sound working as well.

[ghost]

This does not solve the issue for all games. Midnight Club 2 still not syncing for me.

[ghost]

I was too optimistic, the runs in THUGPro are usually short. I've done a longer run and playing back the movie does not always end up with the same behavior.

[InfamousKnight]

Do save states work?

On Sun, Aug 25, 2019, 4:48 PM thomclx notifications@github.com wrote:

I was too optimistic, the runs in THUGPro are usually short. I've done a longer run and playing back the movie does not always end up with the same behavior.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/clementgallet/libTAS/issues/249?email_source=notifications&email_token=AAT4W4OFUOGFJRYI7IEGVKDQGLVZ3A5CNFSM4H4URQK2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD5C3NYA#issuecomment-524662496, or mute the thread https://github.com/notifications/unsubscribe-auth/AAT4W4IVBL5LLQHRRTEEH2LQGLVZ3ANCNFSM4H4URQKQ .

[ghost]

Yes they work. But this is off topic.

[InfamousKnight]

Then for now you can record it in parts. For instance, every 2 minutes you can record a new movie. And then encode them all together.

However, Im not sure if libtas can stop recording movie without closing the window.

On Mon, Aug 26, 2019, 3:47 AM thomclx notifications@github.com wrote:

Yes they work.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/clementgallet/libTAS/issues/249?email_source=notifications&email_token=AAT4W4LA4XG74OG4RJ4SYEDQGODAVA5CNFSM4H4URQK2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD5DSIFA#issuecomment-524755988, or mute the thread https://github.com/notifications/unsubscribe-auth/AAT4W4OZV67TLJYGOA2ZGHTQGODAVANCNFSM4H4URQKQ .

[ghost]

It is not reliable for me as i usually don't make the TAS all at once and we cannot load a savestate when the process is reloaded, we need to advance (or fast forward) to the desired frame. I would better dig into wine and libtas to figure out what happens.

[ghost]

Update: [Maybe Game Specific] (Thug Pro).

I checked XCheckIfEvent and GL Calls, they seems to be executed on the same thread (same std::this_thread::get_id()).

It seems that the game desync if i use fastforward. I tested these scenarios (same results with software rendering on or off):

1. Full play without FF -> Same endings across runs
2. Full play with FF -> Different endings, skipping_draw toggling is inconsistent because it depends on computeFPS which depends on native calls.
3. Full play with FF + computeFPS without native call -> Same endings (depend on constants), consistent skipping_draw toggling.
4. Full play with FF + skip all frames -> Same endings (different from (1,3))
5. Full play with random FF -> Different endings.
6. Full play with FF but skipping_draw always false, just skip sleeps -> Same endings as (1)

Then, i removed all skipping_draw except for glDrawElementsBaseVertex (longest call). I tracked and stored times using native clock(). I replayed the timings with active waits and skipping_draw, and the replay ended as if there were no draw skipped (1).

May be related to #121

[InfamousKnight]

Wait, so you changed wines source files to get THUG2 to sync? Thats a start.

On Thu, Sep 12, 2019, 4:05 PM thomclx notifications@github.com wrote:

Update: [Maybe Game Specific] (Thug Pro). I changed clock_gettime for gettimeofday in wine (dlls/ntdll/time.c -> monotonic_counter). Now i track gettimeofday and it seems to solve my desync issue. I don't know i to solve it in libTAS yet. It does not solve the desync for midnight club2 btw.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/clementgallet/libTAS/issues/249?email_source=notifications&email_token=AAT4W4NVBP7RMDQW37XNHZDQJKOJHA5CNFSM4H4URQK2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD6TC3VI#issuecomment-530984405, or mute the thread https://github.com/notifications/unsubscribe-auth/AAT4W4NCSBO4BNRRLW3VRCLQJKOJHANCNFSM4H4URQKQ .

[ghost]

Ok i was just lucky, I encountered a desync :(.

[InfamousKnight]

I'm not running linux right now, so could someone test midtown madness for input determinism? Its a game pretty close to midnight club(was made by angel soft).

[clementgallet]

Using a decompiler, it looks like Dustforce is using a loop inside a specific thread to check the state of each key using something like:

i = 0x38
vKey = 0;
do {
    ret = GetAsyncKeyState(vKey)
    processInput(vKey, ret);
    vKey += 1;
    i += 4;
    if (i > 0x433) {
        somefunc();
        return;
    }
} while (true)

However, I'm not sure how I could detect that this function did finish.