Issue with ffbwrap and G920
Closed this issue · 22 comments
As per the previous ticket.
When running journalctl -f and playing F1 (just as an example) I get the following message:
kernel: logitech-hidpp-device 0003:046D:C262.0007: Force feedback command queue contains 220 commands, causing substantial delays!
I've just seen that ffbwrap has a throttling option which has solved issues with AC:C and G920. However after adding:
/home/dev/Downloads/ffbtools-master/bin/ffbwrap --update-fix --throttling /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_00005408d2a4768f-event-joystick -- %command%
to steam launch options, the issue persists.
The build was successful and there was no issues there.
output.txt
As for ffbwrap ($ ./bin/ffbwrap --update-fix --throttling $WHEEL -- cat);
It gave the following output:
ERROR: ld.so: object '/home/dev/Downloads/ffbtools-master/bin/../build/libffbwrapper-i386.so' from LD_PRELOAD cannot be preloaded (wrong ELF class: ELFCLASS32): ignored.
For reference:
WHEEL=/dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_00005408d2a4768f-event-joystick
The build did create the file and it is in the ./build folder.
The output is valid. Are your sure that the "command queue" messages persist with ffbwrap?
Yup. Just tested again in case I've done something wrong the first time.
Full error from journalctl
Jun 28 15:26:11 D3v-Desktop kernel: logitech-hidpp-device 0003:046D:C262.0009: Force feedback command queue contains 1420 commands, causing substantial delays!
Command in F1's startup
/home/dev/Downloads/ffbtools-master/bin/ffbwrap --update-fix --throttling /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_00005408d2a4768f-event-joystick -- %command%
This is also what I found in journalctl on game startup
Jun 28 15:24:26 D3v-Desktop steam.desktop[35965]: /bin/sh\0-c\0/home/dev/Downloads/ffbtools-master/bin/ffbwrap --update-fix --throttling /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_00005408d2a4768f-event-joystick -- /home/dev/.local/share/Steam/ubuntu12_32/../ubuntu12_32/reaper SteamLaunch AppId=1080110 -- '/media/dev/games/data/SteamLibrary/steamapps/common/SteamLinuxRuntime_soldier'/_v2-entry-point --verb=waitforexitandrun -- '/home/dev/.local/share/Steam/steamapps/common/Proton 6.3'/proton waitforexitandrun '/media/dev/games/data/SteamLibrary/steamapps/common/F1 2020/F1_2020.exe'\0
The --update-fix shouldn't be needed, although it should do no harm either.
Can you use the --logger option in ffbwrap to write a log for the game and upload it?
I believe I am experiencing the same issue, where ffbwrap --throttling doesn't really work for the g920. The delays are so bad that when I pause the games, ffb effects still play for anywhere between 10-30 seconds. I find that I can get rid of the long delays with --throttle-time at 80-100 but this seems to completely ruin the feel of ffb. I essentially can't use my g920 at all unless I completely disable ffb. What do you suggest?
I am testing on two titles, F1 22 and Dirt Rally 2.0.
These are my startup parameters:
RADV_PERFTEST=gpl /home/ryannathans/Documents/ffbtools/bin/ffbwrap --logger=/home/ryannathans/ffblogs/f1-22 --throttling /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_0000995838ea9909-event-joystick -- %command%
RADV_PERFTEST=gpl /home/ryannathans/Documents/ffbtools/bin/ffbwrap --logger=/home/ryannathans/ffblogs/dirtrally2 --throttling /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_0000995838ea9909-event-joystick -- %command%
This is a snippet of my dmesg while playing with the above games using those parameters:
[32512.885877] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 3980 commands, causing substantial delays!
[32513.078372] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4000 commands, causing substantial delays!
[32513.083633] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4000 commands, causing substantial delays!
[32513.088706] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4000 commands, causing substantial delays!
[32513.387350] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4020 commands, causing substantial delays!
[32513.391866] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4020 commands, causing substantial delays!
[32513.393348] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4020 commands, causing substantial delays!
[32513.397906] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4020 commands, causing substantial delays!
[32513.410797] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4020 commands, causing substantial delays!
[32513.416699] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4020 commands, causing substantial delays!
[32513.936327] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4040 commands, causing substantial delays!
[32513.942327] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4040 commands, causing substantial delays!
[32513.946730] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4040 commands, causing substantial delays!
[32513.948337] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4040 commands, causing substantial delays!
[32513.953423] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4040 commands, causing substantial delays!
[32514.287330] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4060 commands, causing substantial delays!
[32514.291926] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4060 commands, causing substantial delays!
[32514.293323] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4060 commands, causing substantial delays!
[32514.298186] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4060 commands, causing substantial delays!
[32514.318987] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4060 commands, causing substantial delays!
[32514.324453] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4060 commands, causing substantial delays!
[32514.695298] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4080 commands, causing substantial delays!
[32514.698461] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4080 commands, causing substantial delays!
[32514.701297] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4080 commands, causing substantial delays!
[32514.709604] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4080 commands, causing substantial delays!
[32514.971304] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4100 commands, causing substantial delays!
[32514.975037] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4100 commands, causing substantial delays!
[32514.977292] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4100 commands, causing substantial delays!
[32515.198518] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4120 commands, causing substantial delays!
[32515.204323] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4120 commands, causing substantial delays!
[32515.205291] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4120 commands, causing substantial delays!
[32515.208974] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4120 commands, causing substantial delays!
[32515.457278] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4140 commands, causing substantial delays!
[32515.461795] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4140 commands, causing substantial delays!
[32515.472687] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4140 commands, causing substantial delays!
[32515.730282] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4160 commands, causing substantial delays!
[32515.745114] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4160 commands, causing substantial delays!
[32515.750918] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4160 commands, causing substantial delays!
[32515.997266] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4180 commands, causing substantial delays!
[32516.003260] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4180 commands, causing substantial delays!
[32516.007870] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4180 commands, causing substantial delays!
[32516.019101] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4180 commands, causing substantial delays!
[32516.273256] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.279244] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.285962] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.288248] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.291868] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.294242] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.305162] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.311095] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4200 commands, causing substantial delays!
[32516.582239] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4220 commands, causing substantial delays!
[32516.588242] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4220 commands, causing substantial delays!
[32516.594232] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4220 commands, causing substantial delays!
[32516.601026] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4220 commands, causing substantial delays!
[32516.603230] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4220 commands, causing substantial delays!
[32516.608529] logitech-hidpp-device 0003:046D:C262.000E: Force feedback command queue contains 4220 commands, causing substantial delays!
These are the logs for the games:
dirtrally2-20230408201253.log
f1-22-20230408201546.log
Interestingly, assetto corsa competizione has the same ffb issue, but the game allows you to adjust the force feedback frequency in the settings.
The default is 400hz which has the same issue, but reducing it to 200hz fixes the problem without requiring this tool. The ffbwrap tool does not seem to help when running at 400hz (though I didn't try editing the throttling time, as 200hz works without the tool).
Shame all games don't let you set the frequency.
I have created a draft pull request (#31) that resolves this issue. It still needs more testing but works great for me on the Logitech G920 with --throttling and --throttle-time 5
Can you post a log with throttling disabled of DR2. I think there might be an issue with the way throttling is implemented, and maybe there's something else like you have pointed in the PR, but I want to check first what's the unadultered output of the game.
RADV_PERFTEST=gpl /home/ryannathans/Documents/ffbtools/bin/ffbwrap --logger=/home/ryannathans/ffblogs/dirtrally2 /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_0000995838ea9909-event-joystick -- %command%
dirtrally2-20230409222624.log
Is the issue you might be seeing related to throttling play/stop?
I've had now more time to look at this and I think I know what's happening. Your findings in the PR are basically correct.
Based on the log, the game is sending updates and play commands for two effects every 10ms. Even if the effects aren't updated the play commands are still sent.
Throttling is implemented only for updates because that's the most common command executed frequently. Play commands are usually sent once at game start, then everything else are updates. But in this case play commands are sent together with updates. Something unusual and unneeded but it's happening.
Since play commands are executed immediately, updates have to be synch'ed before the play command, and in this case, with play commands sent after every update, throttling isn't working, the play commands are forcing throttling effectively off.
Your solution works for this case but it won't work in other cases where effects end without a stop command. And I want to avoid introducing bad artifacts because this is a testing tool.
I think a better solution would be to throttle play commands the same way than updates. This wouldn't be optimum but would be more correct. A more optimum solution would be to detect the play commands that aren't really needed, based not only on stop commands, but also on the length parameter of the previous update. This would be more complex to implement but optimum and correct.
And the really best solution, if that's possible, would be to see what's happening in the driver or the firmware, because I don't think it's within the specs that this wheel can't handle 2 updates and 2 play commands in 10ms. Anything we do here is a cheap workaround for the real issue.
Please, share any more findings and when I have some time I'll try to implement some other workarounds and/or tests.
I have noticed a very weird issue, which may potentially be related to this.
On arch(ffbtools from aur + hidpp logitech g pro wheel from aur) -> ffbwrap works correctly without issues despite showing the same error about libffbwrapper-i386.so
On zorin os(my work laptop / ffbtools from github and hidpp logitech g pro wheel from it's own github installed with dkms) -> if I use ffbwrap the ffb is not present at all yet the log is the same exact one as the arch one, but the issue is that I need ffbwrap to throttle to 19 otherwise the wheel doesn't behave correctly.
I have done a lot of debugging and I wasn't able to find as to why ffbwrap simply disables all of the ffb on zorin(it should be 1:1).
Maybe it's because you're using the latest Github version in Zorin and an older release in Arch.
I made a change last week and maybe it's not working very well. You can download the same release versions you were using on Arch, probably the latest release, not the latest master commit.
I'm waiting for someone to give me feedback on the latest changes because it works on my G29 and I don't have a G920 to test.
I intend to be testing with my G920 soon, just haven't had a chance yet
Maybe it's because you're using the latest Github version in Zorin and an older release in Arch.
I made a change last week and maybe it's not working very well. You can download the same release versions you were using on Arch, probably the latest release, not the latest master commit.
I'm waiting for someone to give me feedback on the latest changes because it works on my G29 and I don't have a G920 to test.
You were right when I recompiled the FFBTools from aur the ffb completely turns off on my Logitech G Pro wheel.
EDIT: Since I use different wheel I will open a thread about it separately.
I've been having the exact same issue with my G920 in Forza Horizon 5 - when I start the game it'll play without FFB for a couple minutes before it kicks in, moving the wheel minutes behind the events that are happening.
I'm running on the most recent commit so 3035e0e is in place, but doesn't seem to be helping as the behaviour stays exactly the same with/without it. In Steam I'm running
ffbwrap --throttling --logger=/home/joe/ffblogs/fh5 /dev/input/by-id/usb-Logitech_G920_Driving_Force_Racing_Wheel_for_Xbox_One_0000184eec7f2113-event-joystick -- %command%
and it's logging correctly (I've also tried with --throttling-time=5 as @ryannathans suggested, but this didn't seem to make a difference. I'm similarly getting
logitech-hidpp-device 0003:046D:C262.0008: Force feedback command queue contains 47060 commands, causing substantial delays!
from dmesg, and my ffbwrap logs quickly fill up to over 20 MB in size in only a couple of minutes, mostly with the following on repeat:
000224927877 > UPLOAD id:0 dir:49288 length:0 delay:0 type:PERIODIC waveform:SINE period:100 magnitude:0 offset:-1 phase:53766 attack_length:0 attack_level:0 fade_length:0 fade_level:0
000224927893 < 0 id:0
000224928279 > UPLOAD id:1 dir:49288 length:0 delay:0 type:PERIODIC waveform:SINE period:33 magnitude:0 offset:-1 phase:53766 attack_length:0 attack_level:0 fade_length:0 fade_level:0
000224928291 < 0 id:1
000224928403 > UPLOAD id:3 dir:0 length:0 delay:0 type:SPRING right_saturation:65535 left_saturation:65535 right_coeff:7935 left_coeff:7935 deadband:0 center:-1
000224928406 < 0 id:3
000224928519 > UPLOAD id:4 dir:0 length:0 delay:0 type:DAMPER right_saturation:0 left_saturation:0 right_coeff:-1 left_coeff:-1 deadband:0 center:-1
000224928525 < 0 id:4
000224928620 > UPLOAD id:2 dir:16429 length:0 delay:0 type:CONSTANT level:-1 attack_length:0 attack_level:0 fade_length:0 fade_level:0
000224928623 < 0 id:2
99% of the log is just this. This looks like it contrasts with @ryannathans DR2 logs, where the game spams PLAY commands. FH5 only sends one PLAY for each of the IDs above, and the rest is all UPLOADs.
I recognise this is a different game so may require a different fix, but does this match up with anything that's been observed before?
Even with throttling, it has to update 5 effects every cycle. 2ms for each update would make for at least 10ms throttling time. Could you try with 10 or higher throttling value?
This has worked, although only with throttling at 20ms or higher. Watching dmesg helped a lot, as it was just a case of adjusting the throttling time until the FFB queue stopped overflowing. Thanks!
A slight wrinkle for anyone else using this wheel on FH5 to watch out for is that FH5 never seems to send STOP or REMOVE commands when it closes (could this be related to throttling or is it just the game being weird?), causing the following to slowly fill up dmesg:
logitech-hidpp-device 0003:046D:C262.000C: Failed to send command to device!
If the game is launched again while this is happening, the wheel won't react to any FFB effects, despite them being sent in the ffbwrap logs. Good news is that it seems to be fixed by unplugging and replugging the wheel's USB.
Thanks for reporting back.
Ffbwrap shouldn't mess with stop and remove commands but I'll check. What's weird is that upon closing the device, which the game should forcibly do when quitting, the effects should be removed automatically.
Another observation that might be related, when I was trying lower throttling values and events were still getting stuck in the queue, I could close FH5 and reopen it and the wheel would start moving from FFB on the main menu. Is this related to the lack of STOP/REMOVE?
Another observation that might be related, when I was trying lower throttling values and events were still getting stuck in the queue, I could close FH5 and reopen it and the wheel would start moving from FFB on the main menu. Is this related to the lack of STOP/REMOVE?
Can you check if anything of this happens when ffbwrap isn't used?
Sorry for the delay, yes this still happens without ffbwrap so it's probably the game's fault.
I'll close this since the original issue is already fixed and the original poster is no longer responding. Please open new issues if problems persist. Thanks.