Hey @magist3r thanks for reporting. Can you give us information about your system (e.g. your distro and also the information from Help->System Information in Steam)? Also, what games do you see this with? I know it applies to all games, but humor me and list one or two, please.

It would also be helpful if you could do the same test you did above, but also gather logs with +pid,+seh,+process,+service,+steam,+plugplay,+explorer in WINEDEBUG and attach them here.

Hi. I use OpenSUSE Tumbleweed. See systeminfo.txt.
I mostly play RE7 and RE2 Remake.

Here are the logs with debug info (I added additional +timestamp key):
4.11.timestamp.log
5.0.timestamp.log

I've noticed that many calls like
NtQueryInformationProcess (0xffffffffffffffff,0x0000001a
takes 2s and more with wine 5.0. And I guess this is the main reason of the slowdown.

Thanks again @magist3r . It could be that QueryInformationProcess call, that particular call invokes a server round trip. Can you get another 5.0 log with +server,+ntdll in addition to the other channels?

This one is huge. Hope it helps.
5.0.zip

Hi! I tried to reproduce the issue, and for me there's not much difference between Proton 4.11 and Proton 5.0. There's a big difference though if I use your wrapper script instead of the Proton debug script (with PROTON_DUMP_DEBUG_COMMANDS).

When using your wrapper I have a lot of fontconfig warnings being printed, and the initial prefix creation takes ~25s compared to ~5s when using the Proton debug script with no fontconfig warnings.

I pinpointed the root cause to missing /lib/i386-linux-gnu and /lib/x86_64-linux-gnu entries in your LD_LIBRARY_PATH, and I think it makes it load the steam runtime fontconfig instead of the system provided one. This might be distribution dependent though, as I'm on Debian.

Could you please see if you can make it try system fontconfig first? Usually I think steam runtime should come after system libraries, unless the library is "pinned" in $STEAMDIR/ubuntu12_32/steam-runtime/pinned_libs_32 or $STEAMDIR/ubuntu12_32/steam-runtime/pinned_libs_64.

Could you please make a log of it with WINEDEBUG=+timestamp,+pid,+tid,+seh,+process,+service,+steam,+plugplay,+explorer,+font,+file? And possibly another with LD_DEBUG=libs to see if it's using steam runtime's fontconfig?

I think the NtQueryInformationProcess thing may be a red herring, there's many thing happening between these two calls.

5.0_1.zip
5.0_2.zip

Thanks! Sadly I still don't see much here, except that for every process, there's ~2s spent right after c_437.nls is loaded. Some more detailed traces could be useful, for instance adding +reg,+module to the previous WINEDEBUG.

However, doing that locally I can see that this is where COMPUTERNAME_Init is called, and this function has changed between Proton 4.11 and 5.0, now calling gethostname / gethostbyname_r every time where it was previously only conditionally doing it. I can imagine how these calls could induce some delay, so in order to check if it's the case, could you try saving this as gethostname.c:

#include <stdlib.h>
#include <string.h>
#include <netdb.h>

int gethostname(char *name, size_t size)
{
    name[0] = 0;
    return 0;
}

int gethostbyname_r(const char *name,
       struct hostent *ret, char *buf, size_t buflen,
       struct hostent **result, int *h_errnop)
{
    struct hostent *host = ret;
    host->h_name = buf + sizeof(*host);
    strcpy(host->h_name, name);
    *result = host;
    return 0;
}

Then build some shared objects with:

gcc -m32 -shared -o gethostname32.so gethostname.c
gcc -shared -o gethostname64.so gethostname.c

And then retry the prefix creation with an additional LD_PRELOAD=<dir>/gethostname64.so:<dir>/gethostname32.so environment (where <dir> is the absolute path where you built the shared objects), to override these functions?

Also, WINEDEBUG=+timestamp,+pid,+tid,+seh,+process,+service,+steam,+plugplay,+explorer,+font,+file,+reg,+module could be useful to see if it works and to get more detail.

Yeah, it's much faster with LD_PRELOAD'ing dummy gethostname functions:

time ./proton-wrapper.sh 5.0 wineboot > 5.0.log 2>&1

real    0m6,349s
user    0m0,009s
sys     0m0,022s

Here is the complete log: 5.0_3.zip

Alright, so I think the main issue comes from your network / DNS configuration. I'm not sure if we have to call these every time though, so there's maybe something that could be done in Wine but I really don't know why this was introduced and there's maybe a good reason.