Controller inputs are ignored for a few seconds following HDMI video mode change

[c0d3h4x0r]

Problem:

The MiSTer process blocks while writing console output to the slow serial port. It cannot handle user input until it finishes writing to the console.

Many games (examples: Sonic the Hedgehog 2 for MegaDrive, or Agony for Amiga) change the core resolution during gameplay. With vscale_mode=4 or vscale_mode=5, that causes an HDMI video mode change. MiSTer remains unresponsive for a noticeable time (~0.5 - 4.0 seconds) after the video mode change while it writes verbose information about the video mode change to the console. The user's controller inputs are ignored during this time, even though the game is still running. This interferes with gameplay.

The duration of unresponsiveness depends upon the size of the user's .ini file, because it gets parsed, processed, and logged twice on every HDMI video mode change.

The impact of the issue varies depending upon the game being played. For games that switch resolutions at the beginning of a new level (such as an action-packed shooter), losing control for a couple seconds at the start is a big problem.

[c0d3h4x0r]

I've posted a workaround for this issue in MiSTer-devel/Scripts_MiSTer#110.

[sorgelig]

That's because "someone" abused HDMI mode change. So you create the problem and now you complain about it.

[c0d3h4x0r]

I did not "abuse" anything. That's a needlessly mean and accusatory response with zero evidence to back it up.

Other people in Discord are also having problems caused by the serial console output being slow and stalling the MiSTer process. They keep thanking me for trying to come up with solutions. Yesterday I saw someone trying to set the serial port to the fastest possible rate as a workaround, which you said is dangerous, so we need a better official solution. It is not only for me. This is a real issue that is impacting real people and legitimate usage scenarios. Please don't dismiss it just because it doesn't personally impact your usage.

You don't like my shell script workaround, okay. You'd rather redirect stdout directly in C code, okay.

The user would need a way to opt in/out. Maybe a new .ini setting? Something like silence_console=0/1? What do you think of that approach?

[birdybro]

There is a potential issue with the [video=] new header option. @zakk4223 knows the most about it, but he's not sure yet what it is.

[c0d3h4x0r]

I think I need to provide at least two different sets of more detailed repro steps. One repro is for standard HDMI mode using vscale_mods 4 or 5. Another repro is for DirectVideo mode. And there may be more repros, too. I need to provide full details for each repro, including the contents of my .ini file and details about my display and input hardware and video chain.

It will take me some time to collect and write up all of this information. Please hold this issue open while I do that. I will follow up.

[birdybro]

I talked to @zakk4223 on discord. There are 3 issues resulting from what Keith is describing here. I'll summarize:

1. The MiSTer.ini parsed debug output is attached to /dev/console, causing a 600ms delay in usb controller inputs when a game changes resolution because it's looking for [video=] headers.
2. If the user has a [video=] header in their MiSTer.ini, it parses the whole MiSTer.ini twice, resulting in a 1.2 second delay in USB controller inputs.
3. The N64 workaround to open the OSD on core load (https://github.com/RobertPeip/Mister64/blob/main/N64.sv#L569-L585) will not work as intended because of the /dev/console output delay if the console output delay is too long.

This is all because Main blocks on write which suspends input polling, as Zakk put it to me a sec ago.

@c0d3h4x0r Sorgelig was not talking about you, he was talking about this PR --> #567 - but he probably mixed you up with this person.

[c0d3h4x0r]

Thank you Kevin! Yes, that's exactly the issue I am reporting.

And thank you for clarifying about the personal confusion. I think sometimes important subtleties get lost in written form.

[sorgelig]

Probably muting debug output while INI reparse on resolution change should help. That was my first post about.
INI parser originally didn't expect to be used more than one time.

[c0d3h4x0r]

That would help some. It sounds like .ini parsing needs some performance work, too.

But even 300-600ms is still too long. It interferes with gameplay. Reducing the amount of logging is good, but not a complete fix.

Logging is never free, but I don't need it unless I'm diagnosing a problem. When I am diagnosing a problem, I accept reduced performance in exchange for more diagnostic info.

Can MiSTer mute all logging by default, with an option to unmute it for troubleshooting? Does that create some other problem?

[sorgelig]

Probably it's possible to redirect stdout to /dev/null programmatically in Main and then all printf will be muted.
I didn't study this subject yet.

[sorgelig]

i've added "debug" option to INI.

[c0d3h4x0r]

Thank you! I will try the new unstable build.

[c0d3h4x0r]

This works great on my end! So much better than the shell script hackery I've been using as a workaround.

I've verified that there's no debug output when debug=0, and the performance issue is resolved. I've also verified that with ;debug=0 or debug=1, the debug output is the same as before and the performance issue is back.

Having the option is fantastic -- thanks again!

[paulb-nl]

If debug logging is causing issues then why is it now enabled by default?

[sorgelig]

Issue happens only if per-resolution ini section is used. For vast majority of users it's not relevant.
I'll see which state of debug is better.

[c0d3h4x0r]

The issue also happens in other cases, even if the .ini file contains no [video= sections.

[c0d3h4x0r]

But to be clear: As long as there's an official way to disable the debug logging, this is a huge improvement, regardless of the default. If someone in Discord reports an issue due to the slow logging, this will provide a safe, official, easy way to help them.

[sorgelig]

ok. debug=0 is now default.