[Bug 9910] New: Interaction delay in menus while searching for missing files (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

Summary: Interaction delay in menus while searching for missing
                    files (CNC: The First Decade CD games)
           Product: Wine
           Version: CVS/GIT
          Platform: Other
        OS/Version: Linux
            Status: UNCONFIRMED
          Severity: enhancement
          Priority: P2
         Component: wine-files
        AssignedTo: [e-mail]
        ReportedBy: [e-mail]

Created an attachment (id=8405)
 --> (http://bugs.winehq.org/attachment.cgi?id=8405)
Clicking on 'OK' button (just before the delay) while playing Red Alert

There is a very noticeable delay in menu repaints (and sound stutters during
this) when navigating menus in C&C:TFD games. During the delay, the mouse
cursor location does not update, and there are graphical effects that I would
typically associate with a slow repaint. I disabled sound and the problem still
occurred. Looking at the error logs, the cause of this is likely due to files
not being able to be found.

I've attached two screenshots (for both Red Alert and Command & Conquer) of
what I clicked on *just before* this delay happened, and associated log files
where a '--- MARK X ---' (X increments from 1 up) was placed in the log just
before the clicking was done.

I noticed this while playing installed games from the 'Command & Conquer: The
First Decade' DVD (noticed initially in Red Alert, but the problem seems to
occur in C&C and Red Alert 2 as well). I think the freely available version of
C&C is the same as on this DVD, which is why I've included logs for that as
well.

Observed on an unpatched GIT tree pulled on 2007-10-01 (after the Wine version
0.9.46 update).

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #1 from David Hall (gringer)   2007-10-05 22:12:12 ---
Created an attachment (id=8406)
 --> (http://bugs.winehq.org/attachment.cgi?id=8406)
 Clicking on 'OK' button (just before the delay) while playing Command &
Conquer

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #2 from David Hall (gringer)   2007-10-05 22:13:57 ---
Created an attachment (id=8407)
 --> (http://bugs.winehq.org/attachment.cgi?id=8407)
Error log for Red Alert (clicking denoted by '--- MARK X ---' entries in the
log

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #3 from David Hall (gringer)   2007-10-05 22:14:42 ---
Created an attachment (id=8408)
 --> (http://bugs.winehq.org/attachment.cgi?id=8408)
Error log for Command & Conquer (clicking denoted by '--- MARK X ---' entries
in the log

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #4 from David Hall (gringer)   2007-10-05 22:18:30 ---
For creating the log, I did the following:

1) export WINEDEBUG="warn+all"
2) mkfifo errorpipe
3) echo "0" > markcount.txt
4) tail -f errorpipe >> error_${game}.log &
5) wine TFDLauncher.exe &> errorpipe
[5 seconds before I clicked on the 'OK', I ran the following]
6) x=$(echo "$(cat markcount.txt) + 1" | bc); echo "--- MARK ${x} ---" >> \
   errorpipe; echo ${x} > markcount.txt

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #5 from Juan Lang   2007-10-05 23:02:34 ---
Why is it looking for the files so bloody many times?  This almost seems like
an app bug rather than a wine bug.  Are the files present?  If not, should they
be?

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #6 from David Hall (gringer)   2007-10-06 00:51:01 ---
My guess is that the files are stored inside one of the MIX files, and as such
would not come up as being present during a search. One possibility is that the
program searches first for (and uses) files in the local directory and, if not
found, then looks in the MIX file.

I know that it is possible to place a custom rules.ini file into the game
directory to change graphics, weapons, behaviour, etc. of units within the
game. Such a "search local, then MIX" behaviour would be consistent with this
use -- perhaps it is looking for files to allow the use of these custom sounds
/ graphics / rules. Looking for files so many times may not be necessary, but
that was not my intended bug issue. I'm concerned with the interaction delay
(essentially "game freezing") when that is happening.

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #7 from David Hall (gringer)   2007-10-06 21:56:26 ---
Created an attachment (id=8425)
 --> (http://bugs.winehq.org/attachment.cgi?id=8425)
C&C log, timestamps added in wine_nt_to_unix_file_name (via WARN, time(NULL))

I added 5 timestamp commands (via the WARN function) throughout the
wine_nt_to_unix_file_name method (1 second resolution), and the log of that
suggests to me that the blocking is not happening during the search for files
(so this bug should probably be reassigned to a different section). I'll try
adding more debug flags via export to get an idea of the dll calls that are
made around that time).

note: I've chopped off the top and bottom of the log to only concentrate on the
part where I was "clicking on OK".

[Bug 9910] Interaction delay in menus while searching for missing files ( CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #8 from David Hall (gringer)   2007-10-06 23:31:17 ---
Created an attachment (id=8429)
 --> (http://bugs.winehq.org/attachment.cgi?id=8429)
5 files indicating system calls during click/interaction delay (Red Alert)

I ran through Red Alert with WINEDEBUG=+all, and extracted the system calls
during that time [grep -e ":Call " -e "Time (mark" errorX.log]. There are 5
files there, all with minimal user interaction (clicking on the Load Game, OK
button, moving mouse).

I used my WARN time stamps to work out where the delay points were in the log
files (included in these files). These files are the sections of the log where
two time stamps differed by ~4 seconds.

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

David Hall (gringer)  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
          Component|wine-files                  |wine-gdi-(printing)
            Summary|Interaction delay in menus  |Interaction delay in menus
                   |while searching for missing |while navigating (CNC: The
                   |files (CNC: The First Decade|First Decade CD games)
                   |CD games)                   |

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #9 from Austin English   2008-04-15 01:28:49 ---
Is this still an issue in current (0.9.59 or newer) wine?

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #10 from Luke Bratch   2008-04-16 01:30:10 ---
David, do not reply to wine-bugs, post in Bugzilla.  Email read:

"Yes, this is still an issue in current wine (at least for 0.9.59), and I
have not observed any fixed version since I reported the bug.

Another observation that I didn't explicitly mention in my original report
was that there was sound stuttering at the same time as the interaction
delay -- the last 1-2 seconds of sound is played a few times over until
the delay finishes.

FWIW, a somewhat similar effect appears in Star Wars: Knights of the Old
Republic
(http://appdb.winehq.org/objectManager.php?sClass=version&iId=4124), where
there is stuttering/repetition of sound after clicking on some menu items
(particularly save/load functions). In KOTOR, at least, this effect gets
progressively worse as the time played increases (and gets better after
quitting and restarting the program)."

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

--- Comment #11 from David Hall (gringer)   2008-05-11 16:00:31 ---
Had another check of this for wine-1.0-rc1, and the bug seems to be fixed (or
at least significantly reduced). There is a small delay on refreshing the main
menu C&C and Red Alert, but nowhere near as annoying as what it was previously
(and the music/sound stutter has disappeared.

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

Lei Zhang  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|UNCONFIRMED                 |RESOLVED
         Resolution|                            |FIXED

--- Comment #12 from Lei Zhang   2008-05-11 18:37:54 ---
reported (mostly) fixed/

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

Alexandre Julliard  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #13 from Alexandre Julliard   2008-05-23 10:38:10 ---
Closing bugs fixed in 1.0-rc2.

[Bug 9910] Interaction delay in menus while navigating (CNC: The First Decade CD games)

http://bugs.winehq.org/show_bug.cgi?id=9910

Austin English  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
            Version|CVS/GIT                     |unspecified