logging control

[axet]

Is your feature request related to a problem? Please describe.

log spamming when running the game (also no error message).

gamemodeauto: 
gamemodeauto: 
gamemodeauto: 
gamemodeauto: 
gamemodeauto: 
gamemodeauto: 

Describe the solution you'd like

having GAMEMODE_LOG=none env variable

Describe alternatives you've considered

none

Additional context

most wine wrappers / libs has option to disable logging for example:

      export WINEDEBUG=-all,$WINEDEBUG
      export DXVK_LOG_LEVEL=none
      export VKD3D_DEBUG=none
      export MANGOHUD_LOG_LEVEL=off

Currently gamemode spamming using stderr channel:

fprintf(stderr, "gamemodeauto: %s\n", gamemode_error_string());

[HenrikHolst]

Looking at the code this logging is only called when there is a problem so the bug looks to be more that gamemode_error_string() returns nothing on what the error is than that the logging is there in the first place. This logging is done in 4 places in lib/gamemode_client.h so my initial idea would have been to add a number to each one to at least determine which one of them that is failing for you to have a start of finding out why you get no error string.

[axet]

Booth 'REAL_internal_gamemode_request_start' and 'REAL_internal_gamemode_request_end' are failing.

[axet]

That part of the code:

    if (res == -1 && dbus_error_is_set(&err))
        log_error("D-Bus error: %s", err.message);

Simplifying the check, showing error d-bus error with no text message

    if (res == -1)
        log_error("D-Bus error: %s", err.message);

[HenrikHolst]

I wonder if this is possible connected to #426 since this is related to dbus errors and inhibiting the screen lock is done via dbus aswell.

[HenrikHolst]

dbus_error_is_set

well this atleast means that make_request() failed but that err wasn't set (aka no D-BUS error)

[HenrikHolst]

so it should be this code in make_request() (client_impl.c)

    dbus_error_init(&err);
    res = -1;
    if (dbus_set_error_from_message(&err, msg)) {
        dbus_set_error(error,
                       err.name,
                       "Could not call method '%s' on '%s': %s",
                       method,
                       dest,
                       err.message);
    } else if (!dbus_message_iter_init(msg, &iter) ||
               dbus_message_iter_get_arg_type(&iter) != DBUS_TYPE_INT32) {
        dbus_set_error(error, DBUS_ERROR_INVALID_SIGNATURE, "Failed to parse response");
    } else {
        dbus_message_iter_get_basic(&iter, &res);
    }

    /* free the local error */
    if (dbus_error_is_set(&err))
        dbus_error_free(&err);

    return res;

The first if sets error so it isn't that one, so its either the else if or the call to dbus_message_iter_get_basic() that fails leaving res at -1 but setting no error to the error variable.

[axet]

Same. No error message and -1 as res.

[HenrikHolst]

Not sure what you mean by same? I listed the code as it is, so no change. What I would do is try to add some logging inside that if else-if else to see why ret is still -1

[axet]

No. I just applied the code you posted. I did not check if it is a same code :)

[HenrikHolst]

hehe :)

[axet]

This is my full log of running wine app under gamemode. Notice different amount of "start" (22) and "stop" (14) commands. Some "start" commands were successful. D-bus error line only appears when ret == -1

d3 -l
wine folder found: /media/axet/128GB/Games/Diablo III
winearch set to win64
working directory: /media/axet/128GB/Games/Diablo III/D3
gamemodeauto3: start 
gamemodeauto3: start 
GameMode ERROR: D-Bus error: (null)
gamemodeauto3: D-Bus error: (null)
gamemodeauto3: start 
GameMode ERROR: D-Bus error: (null)
gamemodeauto3: D-Bus error: (null)
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto5: stop 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto5: stop 
gamemodeauto3: start 
gamemodeauto5: stop 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto5: stop 
gamemodeauto3: start 
gamemodeauto3: start 
gamemodeauto5: stop 
gamemodeauto3: start 
gamemodeauto5: stop 
gamemodeauto5: stop D-Bus error: (null)
gamemodeauto5: stop 
gamemodeauto5: stop 
gamemodeauto5: stop 
gamemodeauto5: stop 
gamemodeauto5: stop 
gamemodeauto5: stop 
gamemodeauto5: stop 
GameMode ERROR: D-Bus error: (null)
gamemodeauto5: D-Bus error: (null)

[HenrikHolst]

Now I'm not 100% clear with the inner workings of gamemode but I find it strange that gamemodeauto is even a thing here, AFAIK that is some lib that is used in LD_PRELOAD to force in gamemode instead of running it under gamemoderun (but I can be mistaken).

Does the same problems happen if you just run the "gamemode-simulate-game" binary?

[axet]

gamemode-simulate-game works fine. no errors reported.

[HenrikHolst]

ok looks like I am extremely thick... gamemoderun is just a script that uses LD_PRELOAD so ofc you would trigger the auto-stuff there, meanwhile the gamemode-simulate-game is just the main.c from examples/ so it does a "proper" connect to gamemoded via d-bus.

so there is for some reason a difference on your system if things are launched via the d-bus api directly or by injecting libgamemodeauto.so into the running application.

[axet]

Maybe due to different ABI? x32 / x64? I'm using wine64, but who knows...