4.0.1.0 bugs

[filbo]

I 'pulled' last night, built, and the result was nearly unusable for me -- then today I see it's a declared version :(

A confluence of small things adds up to pain:

1. There's a longstanding bug I've been chasing where *sometimes* RnD gets in a mood where typing number keys changes the speed, despite no shift key being held. It was doing that last night.
2. '1' is my key for toggling single-step mode (which I do a lot), while '[any shift]-1' is 'go astonishingly slow'.
3. Both take effect at once.
4. It's hard to get *out* of ultra-slow mode + single-step; input only seems to be recognized at very limited moments in the cycle, so I'm frantically hitting ctrl-9 or whatever, trying to wake it up
5. Now debug messages don't print, so I can't even see visually when one of my frantic attempts has succeeded
6. Running with '-debug' to get debug messages to print, prints lots of extra messages
7. Running with '-debug' makes warp mode replay ('51555' with my keys) excruciatingly slower. e.g. on the level I just completed, if I run without '-debug', '51555' takes about 1 second to get to 03:58, nearly the end. With '-debug' it takes about 13 seconds, showing a meter averaging about 800 FPS. (It is simply the display of FPS which slows it down by a factor of 13?!?)
8. Of course once I've turned on '-debug' it doesn't reproduce the '1-without-shift' bug, so I don't get to undo that... :(

[filbo]

Part 7 is caused by redrawing the FPS about 4000 times per second. It needs to be scaled according to GameFrameDelay.

And is that actually calculating frames per second, or frames per GameFrameDelay-adjusted game-time-second?

[filbo]

Actually it seems like it would be better to use gettimeofday() / equivalent, to actually issue FPS at .5s intervals rather than some crazy calculated thing.

Didn't even try to figure out the correct way to calculate the *value* of FPS, I'm just worrying about the interval between reports. 4000 times a second is too many :)

[filbo]

This fixes it (part 7), and I promise it's wrong :)

It causes recalc and draw every .5s. Problems:

- looks like if FPS goes down a digit (1000 to 999), doesn't erase the high digit(s)
- the actual calculated numbers look crazy to me
- is probably FP(game-second) rather than FP(realtime-second)
- might need porting to Windows, Mac, Android, etc.? gettimeofday() certainly could be universal by now, and M & A should have it, but ... who knows.
- (delta_us < 0) prevents latent bug if that ever happens (one extra display frame and time is caught up / back to normal...)

Code: Select all

diff --git a/src/game.c b/src/game.c
index 8978e70..8efa514 100644
--- a/src/game.c
+++ b/src/game.c
@@ -11217,18 +11217,26 @@ void GameActionsExt()
     static unsigned int fps_counter = 0;
     static int fps_frames = 0;
     unsigned int fps_delay_ms = Counter() - fps_counter;
+    static struct timeval last_time = { 0, 0 }, this_time;
+    long delta_us;
 
     fps_frames++;
 
-    if (fps_delay_ms >= 500)   /* calculate fps every 0.5 seconds */
+    gettimeofday(&this_time, NULL);
+    delta_us = 1000000 * (this_time.tv_sec - last_time.tv_sec)
+                       + this_time.tv_usec - last_time.tv_usec;
+
+    if (delta_us > 500000 | delta_us < 0)     /* calculate fps every 0.5 seconds */
     {
+      last_time = this_time;
       global.frames_per_second = 1000 * (float)fps_frames / fps_delay_ms;
 
       fps_frames = 0;
       fps_counter = Counter();
+
+      redraw_mask |= REDRAW_FPS;
     }
 
-    redraw_mask |= REDRAW_FPS;
   }
 }

[Holger]

Thanks for the detailed list of bugs. It shouldn't be too hard to fix most of them, I think.

The one change I did very shortly before releasing 4.0.1.0 was the change in handling debug messages. This was quite broken before, because there is a "--debug" command line option to enable them since long ago, but debug messages were always printed unconditionally nevertheless, while warning messages were only issued with the "--verbose" option enabled. (To make things even more confusing, the output of some (most?) of those debug messages was limited by "#ifdef DEBUG" preprocessor commands, so they were enabled/disabled by compiling with/without the "-DDEBUG" option.)

This was the first step to clean up that "-DDEBUG" / "--debug" mess. The main problem is that one usually wants debug messages for only a small part of the program (that is to be debugged), so it should be possible to specify the part (or parts) to be debugged without the need of recompiling the program (or even the need of modifying some preprocessor definitions; see the first lines of "src/events.c" for an example).

So, the solution would be to specify the sub-systems to be inspected more closely, and only get debug messages for that specific part of the program. This could be achieved by an option like "--debug-subsystem SYSTEM1,SYSTEM2,...,SYSTEMn" or something like that.

Regarding the "FPS" display, this was indeed a quick and dirty hack. I nearly didn't know that it still existed, not to speak of that it still works (and yes, it currently messes up (slows down) warp forward, and should either be suppressed in this mode or limited to being drawn only every 0.5 or 1 s, just like you suggested.

Regarding (4): Does this problem only occur in single-step mode? (BTW: Does it make sense to combine single-step mode and ultra-slow mode? Maybe yes. I'll check what's the problem of leaving slow-mode without leaving single-step mode...)

Regarding (1): Not sure about this one. I'll have a look into the code to see what might happen here. But if it only happens very rarely, it might be hard to find the cause for this bug.

[filbo]

FPS display actually works very nicely with the patch I posted. As I said, it's wrong, needs your touch to make it right, but it's basically what's needed. Drawing every .5s seems fine; even if it was .1s it wouldn't noticeably slow things down (vs. the .00025s it was actually doing...)

Not sure if #4 only happens in single-step. I never intentionally go into the slowest speed; *only* when a '1' (toggle single-step) is mistakenly taken for 'modifier-1' (ultra-slow mode), therefore only at moments when I was either just in or just entering single-step.

> Does it make sense to combine single-step mode and ultra-slow mode?

I can read this two ways, so I will answer both:

Q1. As a user of the program, would I ever have a reason to put it in single-step and ultra-slow modes at the same time?
A1: no, but only because I never want to use ultra-slow mode. I *do* use single-step plus various other speed levels, and the whole thing should be generalized and orthogonal, so yes it *should* be possible to get into both modes at once (just not involuntarily!)

Q2. As the programmer, should you make it so that one or the other of those modes implies the other? Absolutely not! This probably isn't what you meant, but just in case it was. No way!

Actually one of the most useful modes is 'modifier-9' (fastest / no frame delay at all) + single-step. Then every single-step action is completed 'instantly', which helps quite a bit with the input parsing problems. You essentially never hit the bad windows because response is so swift.

Regarding (1) (unmodified number keys being mis-parsed as modified). I'm pretty sure this is because you're plumbing the SDL modifier word, which has a bunch of bits in it, all the way through. You should mask it down to just ctrl, alt, shift, win/meta/whatever. Um. In SDL terms, AND it with (KMOD_CTRL | KMOD_SHIFT | KMOD_ALT | KMOD_GUI) -- thus removing KMOD_NUM, KMOD_CAPS, KMOD_MODE (whatever that is), KMOD_RESERVED.

-- I just confirmed that having NumLock on causes the problem. Pretty sure I didn't have Num or Caps turned on (I'd have noticed the light on the kbd); but, well, I've seen endless OS bugs over the years where those states get out of sync with the LEDs. Plus, no idea what part of SDL might turn on KMOD_MODE or any other random bits.

[filbo]

Of course it is *my* fault, from some time ago, that the speed keys are mapped to [any modifier]-[digit]. I still think that's right, it just needs to be restricted to modifiers that actually make sense. I wanted it to respond to all modifiers because different GUIs trap or otherwise allocate different ones, but no GUI takes over every modifier key...

[Holger]

FPS display actually works very nicely with the patch I posted. As I said, it's wrong, needs your touch to make it right, but it's basically what's needed.

Yes, it looks OK, so I should just use it. I will also change it so that "--debug" does not automatically enable it. Using a "cheat mode" shortcut (like ":fps") to enable it when needed should be better than always unconditionally activating it.

This probably isn't what you meant, but just in case it was. No way!

No, "Q1/A1" was the correct interpretation.

Actually one of the most useful modes is 'modifier-9' (fastest / no frame delay at all) + single-step. Then every single-step action is completed 'instantly', which helps quite a bit with the input parsing problems. You essentially never hit the bad windows because response is so swift.

This sounds reasonable and logical!

You should mask it down to just ctrl, alt, shift, win/meta/whatever.

Definitely yes! I thought I would already do this, but indeed not (just checked in src/events.c)!

I just confirmed that having NumLock on causes the problem.

Good to know what caused it! So you suggestion above should indeed fix this one.

the speed keys are mapped to [any modifier]-[digit]. I still think that's right, it just needs to be restricted to modifiers that actually make sense.

ACK!

[filbo]

Ah, did not mean to say that capslock or numlock was the cause in my cases; only that I was able to intentionally reproduce it by turning those on.

I think it was *not*, because my keyboard has lights for those states and I would have noticed. (Except of course if X or whatever had gotten one of them out of sync with the LEDs)

As I expect I'll be `git pull`ing an update soon which wipes out the extra bits, I don't think I'll ever know for sure what caused it; but it won't matter...

Thanks :)

[Holger]

This fixes it (part 7), and I promise it's wrong

Thanks again for the patch! In fact, only the following part of the patch was required to fix the problem:

Code: Select all

diff --git a/src/game.c b/src/game.c
index 8978e70..bc402ec 100644
--- a/src/game.c
+++ b/src/game.c
@@ -11226,9 +11226,9 @@ void GameActionsExt()
 
       fps_frames = 0;
       fps_counter = Counter();
-    }
 
-    redraw_mask |= REDRAW_FPS;
+      redraw_mask |= REDRAW_FPS;
+    }
   }
 }

The counter stuff is already done right by using "Counter()" instead of "gettimeofday()", which returns the number of milliseconds since the game was started.

- looks like if FPS goes down a digit (1000 to 999), doesn't erase the high digit(s)

This is also fixed now. (I've also made FPS display a bit nicer.)

Then, it is now independent from "--debug" mode, but can simply always be enabled by typing ":fps" in the main menu. It can also be permanently activated by adding "debug.show_frames_per_second: true" to your "setup.conf" file.

- the actual calculated numbers look crazy to me

Well, they look indeed a bit crazy in invisible warp mode, so "frames per second" may be misleading, as the frames are not always drawn, but drawing is skipped (as long as the time counter and tape display are unchanged), so these "frames" also include the frames that are not drawn to speed things up. In the other cases (visible play, ffwd and warp mode), they are correct.

- is probably FP(game-second) rather than FP(realtime-second)

No, the seconds are real seconds.

- might need porting to Windows, Mac, Android, etc.? gettimeofday() certainly could be universal by now, and M & A should have it, but ... who knows.

Using "Counter()", it uses "SDL_GetTicks()" internally, and works on all platforms supported by R'n'D.

- (delta_us < 0) prevents latent bug if that ever happens (one extra display frame and time is caught up / back to normal...)

This special case is also already handled correctly by using "Counter()".

In SDL terms, AND it with (KMOD_CTRL | KMOD_SHIFT | KMOD_ALT | KMOD_GUI)

Also fixed now. NumLock & Co. now do not count as modifier keys anymore.

Please "git pull && make run"!

[filbo]

> only the following part of the patch was required to fix the problem:

heh. Just moving a brace...

> Please "git pull && make run"!

I'm traveling this week, laptop not setup right for that, but I'll look at it next weekend... thanks!