Skip to content

Commit

Permalink
[DEBUG-ONLY] Fix rare possibility of wcs_phase2_commit_wait() incorre…
Browse files Browse the repository at this point in the history
…ctly returning FALSE

Background
----------
* The `stress_1/concurr_small` subtest failed in a rare test run on an AARCH64 system with the
  following symptom.

  ```diff
  --- concurr_small/concurr_small.diff ---
  118a119,164
  > host:stress_1/concurr_small/instance2/stress_oli.out
  > %YDB-F-ASSERT, Assert failed in sr_unix/ss_release.c line 184 for expression (FALSE)
  ```

* Below is the C-stack of the core file.

  ```
  (gdb) where
  #0  __pthread_kill (threadid=<optimized out>, signo=3) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
  #1  gtm_dump_core () at sr_unix/gtm_dump_core.c:74
  #2  gtm_fork_n_core () at sr_unix/gtm_fork_n_core.c:163
  #3  ch_cond_core () at sr_unix/ch_cond_core.c:80
  #4  rts_error_va (csa=0x0, argcnt=7, var=...) at sr_unix/rts_error.c:198
  #5  rts_error_csa (csa=0x0, argcnt=7) at sr_unix/rts_error.c:99
  #6  ss_release (ss_ctx=0xffffeb411fc8) at sr_unix/ss_release.c:184
  #7  mupip_integ () at sr_port/mupip_integ.c:813
  #8  mupip_main (argc=7, argv=0xffffeb416008, envp=0xffffeb416048) at sr_unix/mupip_main.c:122
  #9  dlopen_libyottadb (argc=7, argv=0xffffeb416008, envp=0xffffeb416048, main_func=0xaaaad2db1650 "mupip_main") at sr_unix/dlopen_libyottadb.c:151
  #10 main (argc=7, argv=0xffffeb416008, envp=0xffffeb416048) at sr_unix/mupip.c:22
  ```

Issue
-----
* The assert that failed was in line 184 below.

  **sr_unix/ss_release.c**
  ```c
    173  if (dba_bg == cs_data->acc_meth)
    174  {
    175          /* Now that we have crit, wait for any pending phase2 updates to finish. Since phase2 updates happen
    176           * outside of crit, we dont want them to keep writing to the snapshot file even after the snapshot
    177           * is complete. This is needed as otherwise a GT.M process might see the value of csa->snapshot_in_prog
    178           * as TRUE and before it can proceed any further(starvation, maybe), we went ahead and removed the
    179           * snapshot file(below). Now, if the GT.M process resumes execution, it might end up writing
    180           * the before image to a temporary file which is no longer available.
    181           */
    182          if (cnl->wcs_phase2_commit_pidcnt && !wcs_phase2_commit_wait(csa, NULL))
    183          {
    184                  assert(FALSE);
    185                  gtm_putmsg_csa(CSA_ARG(csa) VARLSTCNT(7) ERR_COMMITWAITSTUCK, 5, process_id, 1,
    186                                  cnl->wcs_phase2_commit_pidcnt, DB_LEN_STR(gv_cur_region));
    187          }
    188  }
  ```

* The reason it failed was that `cnl->wcs_phase2_commit_pidcnt` was a non-zero value at line 182 above
  but the call to `wcs_phase2_commit_wait()` returned FALSE at line 182.

* Below is the relevant code flow inside that function call.

  **sr_port/wcs_phase2_commit_wait.c**
  ```c
    153  if (NULL == cr)
    154  {
    155          value = cnl->wcs_phase2_commit_pidcnt;
    156          if (!value)
    157                  return TRUE;
    158          if (lcnt == lcnt_isprcalv_next)
    159          {       /* Do "is_proc_alive" check. This section is very similar to the "NULL == cr" section
    160                   * at the end of this module in terms of book-keeping array maintenance.
    161                   */
    162                  crarray_index = 0;
    163                  any_blocked = FALSE;
    164                  for (curcr = cr_lo; curcr < cr_top;  curcr++)
    165                  {
    166                          blocking_pid = curcr->in_tend;
    167                          if (!blocking_pid || (blocking_pid == process_id))
    168                                  continue;
    169                          any_blocked = TRUE;
      .
      .
    210                  }
    211                  if (was_crit && (crarray_index || !any_blocked) && (curcr == cr_top))
    212                  {       /* We hold crit, found no alive pids in phase2 commit, and found either at least one
    213                           * dead pid or no blocking pids, the latter indicating that the wcs_phase2_commit_pidcnt
    214                           * is wrong.
    215                           * No need to wait any more. Return FALSE right away. Caller will invoke "wcs_recover"
    216                           * to fix the situation.
    217                           */
    218                          return FALSE;
    219                  }
  ```

* What I suspect happened is that at line 155, we found `value` to be a non-zero value. This means a concurrent
  process is in phase2 of commit and some cache-record has a non-zero value of `cr->in_tend` pointing to that
  process id. But before we went to examine that particular cache-record in line 167, the concurrent process
  that was in the phase2 commit finished its phase2 commit and reset `cr->in_tend` back to 0. Therefore,
  we found no cache-record with a non-zero `cr->in_tend` in the `for` loop (lines 164 to 210). This means
  `any_blocked` was still set to FALSE when we came to line 211.

  And since we were holding crit when we entered `wcs_phase2_commit_wait()`, the variable `was_crit` was set
  to TRUE.

  Therefore, we were in a situation where `was_crit` was TRUE, `any_blocked` was FALSE and `curcr` was
  equal to `cr_top` because we scanned all the cache-records in the `for` loop of line 164.

  And because of this, we went inside the `if` at line 211 above and returned FALSE at line 218.

  And this caused the assert failure in the caller function.

  In this case, returning FALSE was incorrect. The comment at line 213 indicates that we found `no blocking pids`
  and that this indicates `that the wcs_phase2_commit_pidcnt is wrong`. But there is nothing wrong with the count.
  The count changed concurrently in between line 155 and 211 and we did not take that into account.

Fix
---
* The fix is simple and is to `re-check` the value of `cnl->wcs_phase2_commit_pidcnt` in line 211 after
  checking `any_blocked` and if it is still non-zero, only then return FALSE as it then clearly indicates
  something wrong with the `wcs_phase2_commit_pidcnt` counter.

* So we would continue to the next iteration of the outer `for` loop (based on the `lcnt` variable) and
  that iteration would see `value` to be 0 at line 155 and return TRUE at line 157 thereby avoiding this
  incorrect return.

Notes
-----
* In Debug builds, one would see an assert failure like in this case.

* In Release builds, this particular caller `ss_release()` does not do that but most other callers of
  `wcs_phase2_commit_wait()` would call `wcs_recover()` in case the process is already holding crit
  and the function returns FALSE. And that would effectively be a no-op since by that time the
  `wcs_phase2_commit_pidcnt` is already 0. One would see some syslog messages indicating the unnecessary
  cache recovery occurred but otherwise no user-visible symptoms should happen. Therefore, no issue
  number is assigned to this commit.
  • Loading branch information
nars1 committed Mar 28, 2023
1 parent 3460d72 commit 99b1040
Showing 1 changed file with 4 additions and 4 deletions.
8 changes: 4 additions & 4 deletions sr_port/wcs_phase2_commit_wait.c
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
* Copyright (c) 2008-2019 Fidelity National Information *
* Services, Inc. and/or its subsidiaries. All rights reserved. *
* *
* Copyright (c) 2018 YottaDB LLC and/or its subsidiaries. *
* Copyright (c) 2018-2023 YottaDB LLC and/or its subsidiaries. *
* All rights reserved. *
* *
* This source code contains the intellectual property *
Expand Down Expand Up @@ -208,10 +208,10 @@ boolean_t wcs_phase2_commit_wait(sgmnt_addrs *csa, cache_rec_ptr_t cr)
}
}
}
if (was_crit && (crarray_index || !any_blocked) && (curcr == cr_top))
if (was_crit && (crarray_index || (!any_blocked && (0 != cnl->wcs_phase2_commit_pidcnt)))
&& (curcr == cr_top))
{ /* We hold crit, found no alive pids in phase2 commit, and found either at least one
* dead pid or no blocking pids, the latter indicating that the wcs_phase2_commit_pidcnt
* is wrong.
* dead pid OR no blocking pids when the wcs_phase2_commit_pidcnt is still non-zero.
* No need to wait any more. Return FALSE right away. Caller will invoke "wcs_recover"
* to fix the situation.
*/
Expand Down

0 comments on commit 99b1040

Please sign in to comment.