Fix module assertion crash when timer and timeout are unlocked in the same event loop

[enjoy-binbin]

When we use a timer to unblock a client in module, if the timer
period and the block timeout are very close, they will unblock the
client in the same event loop, and it will trigger the assertion.
The reason is that in moduleBlockedClientTimedOut we will protect
against re-processing, so we don't actually call updateStatsOnUnblock
(see #12817), so we are not able to reset the c->duration.

The reason is unblockClientOnTimeout() didn't realize that bc had
been unblocked. We add a function to the module to determine if bc
is blocked, and then use it in unblockClientOnTimeout() to exit.

There is the stack:

beforeSleep
blockedBeforeSleep
handleBlockedClientsTimeout
checkBlockedClientTimeout
unblockClientOnTimeout
unblockClient
resetClient
-- assertion, crash the server
'c->duration == 0' is not true

[enjoy-binbin]

second commit:

=== REDIS BUG REPORT START: Cut & paste starting from here ===
44562:M 30 Jan 2024 22:24:25.784 # === ASSERTION FAILED ===
44562:M 30 Jan 2024 22:24:25.784 # ==> networking.c:2089 'c->duration == 0' is not true

------ STACK TRACE ------

Backtrace:
0   redis-server                        0x000000010ad9b5fe resetClient + 238
1   redis-server                        0x000000010ae402ba unblockClient + 394
2   redis-server                        0x000000010ae40fae unblockClientOnTimeout + 78
3   redis-server                        0x000000010ae9b356 checkBlockedClientTimeout + 86
4   redis-server                        0x000000010ae9b82f handleBlockedClientsTimeout + 239
5   redis-server                        0x000000010ae410d9 blockedBeforeSleep + 9
6   redis-server                        0x000000010ad6e467 beforeSleep + 279
7   redis-server                        0x000000010ad5fb6f aeProcessEvents + 159
8   redis-server                        0x000000010ad604cf aeMain + 63
9   redis-server                        0x000000010ad7ee22 main + 4066
10  dyld                                0x00007ff817c9c41f start + 1903

------ STACK TRACE DONE ------

[enjoy-binbin]

the second crash seem introduced in #12817, in the test case, we did not clear the duration.
@oranagra i am short on time, please suggest a fix (if you have an idea soon)

    if (!from_module)
        updateStatsOnUnblock(c, bc->background_duration, 0, server.stat_total_error_replies != prev_error_replies);

[oranagra]

i think we can give up the assertion in resetClient. @sundb PTAL and tell us if you have a better idea.

[sundb]

@enjoy-binbin Not sure it's a good idea to remove this assertion, i need some time to recall it.

[enjoy-binbin]

Not sure it's a good idea to remove this assertion, i need some time to recall it.

sure, take your time, i just gona push the commit first and see how the Daily situation. https://github.com/enjoy-binbin/redis/actions/runs/7720486045

please also take a look at the top comment, see if i get it right.

[sundb]

eventloop()
  - timer_callback()
    - RM_UnblockClient()
      - moduleUnblockClientByHandle() /* set bc->unblocked to 1, and add bc to moduleUnblockedClients */
  - handleBlockedClientsTimeout()
    - replyToBlockedClientTimedOut()
      - moduleBlockedClientTimedOut() /* since bc->unblocked is 1, return ASAP and doesn't call  
                                       * updateStatsOnUnblock() */
    - unblockClient() /* crash due to not calling updateStatsOnUnblock() which will
                           reset c->duration */

The main reason for this is that bc was unblocked when the timer timeout, both timeouts were triggered at the same time in the same event loop, but unblockClientOnTimeout() didn't realize that bc had been unblocked.
We can add an method to the module to determine if bc is blocked, and then use it in unblockClientOnTimeout() to exit ASAP.
@oranagra @enjoy-binbin WDYT?

[enjoy-binbin]

The main reason for this is that bc was unblocked when the timer timeout, both timeouts were triggered at the same time in the same event loop, but unblockClientOnTimeout() didn't realize that bc had been unblocked.
We can add an method to the module to determine if bc is blocked, and then use it in unblockClientOnTimeout() to exit ASAP.

great, this is consistent with what i understood in the top comment, and the fix sounds like a good idea

[oranagra]

ok. good.
maybe fix it in two separate PRs, otherwise i'll have to avoid squash-merging it, or replace the references to first commit and second commit with references to functions.

[enjoy-binbin]

daily: https://github.com/redis/redis/actions/runs/7723190406

[oranagra]

ready for merge?

[enjoy-binbin]

ready for merge?

yes, i think so