storage/test/test_deadlock_detector.cpp

   1 /* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4 -*-
   2  * vim: sw=4 ts=4 et :
   3  * This Source Code Form is subject to the terms of the Mozilla Public
   4  * License, v. 2.0. If a copy of the MPL was not distributed with this
   5  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
   6
   7 /**
   8  * Note: This file is a copy of xpcom/tests/TestDeadlockDetector.cpp, but all
   9  *       mutexes were turned into SQLiteMutexes.
  10  */
  11
  12 #include "prenv.h"
  13 #include "prerror.h"
  14 #include "prio.h"
  15 #include "prproces.h"
  16
  17 #include "nsMemory.h"
  18
  19 #include "mozilla/CondVar.h"
  20 #include "mozilla/ReentrantMonitor.h"
  21 #include "SQLiteMutex.h"
  22
  23 #include "TestHarness.h"
  24
  25 using namespace mozilla;
  26
  27 /**
  28  * Helper class to allocate a sqlite3_mutex for our SQLiteMutex.  Also makes
  29  * keeping the test files in sync easier.
  30  */
  31 class TestMutex : public mozilla::storage::SQLiteMutex
  32 {
  33 public:
  34     TestMutex(const char* aName)
  35     : mozilla::storage::SQLiteMutex(aName)
  36     , mInner(sqlite3_mutex_alloc(SQLITE_MUTEX_FAST))
  37     {
  38         NS_ASSERTION(mInner, "could not allocate a sqlite3_mutex");
  39         initWithMutex(mInner);
  40     }
  41
  42     ~TestMutex()
  43     {
  44         sqlite3_mutex_free(mInner);
  45     }
  46
  47     void Lock()
  48     {
  49         lock();
  50     }
  51
  52     void Unlock()
  53     {
  54         unlock();
  55     }
  56 private:
  57   sqlite3_mutex *mInner;
  58 };
  59
  60 static PRThread*
  61 spawn(void (*run)(void*), void* arg)
  62 {
  63     return PR_CreateThread(PR_SYSTEM_THREAD,
  64                            run,
  65                            arg,
  66                            PR_PRIORITY_NORMAL,
  67                            PR_GLOBAL_THREAD,
  68                            PR_JOINABLE_THREAD,
  69                            0);
  70 }
  71
  72 #define PASS()                                  \
  73     do {                                        \
  74         passed(__FUNCTION__);                   \
  75         return NS_OK;                           \
  76     } while (0)
  77
  78 #define FAIL(why)                               \
  79     do {                                        \
  80         fail("%s | %s - %s", __FILE__, __FUNCTION__, why); \
  81         return NS_ERROR_FAILURE;                \
  82     } while (0)
  83
  84 //-----------------------------------------------------------------------------
  85
  86 static const char* sPathToThisBinary;
  87 static const char* sAssertBehaviorEnv = "XPCOM_DEBUG_BREAK=abort";
  88
  89 class Subprocess
  90 {
  91 public:
  92     // not available until process finishes
  93     int32_t mExitCode;
  94     nsCString mStdout;
  95     nsCString mStderr;
  96
  97     Subprocess(const char* aTestName) {
  98         // set up stdio redirection
  99         PRFileDesc* readStdin;  PRFileDesc* writeStdin;
 100         PRFileDesc* readStdout; PRFileDesc* writeStdout;
 101         PRFileDesc* readStderr; PRFileDesc* writeStderr;
 102         PRProcessAttr* pattr = PR_NewProcessAttr();
 103
 104         NS_ASSERTION(pattr, "couldn't allocate process attrs");
 105
 106         NS_ASSERTION(PR_SUCCESS == PR_CreatePipe(&readStdin, &writeStdin),
 107                      "couldn't create child stdin pipe");
 108         NS_ASSERTION(PR_SUCCESS == PR_SetFDInheritable(readStdin, true),
 109                      "couldn't set child stdin inheritable");
 110         PR_ProcessAttrSetStdioRedirect(pattr, PR_StandardInput, readStdin);
 111
 112         NS_ASSERTION(PR_SUCCESS == PR_CreatePipe(&readStdout, &writeStdout),
 113                      "couldn't create child stdout pipe");
 114         NS_ASSERTION(PR_SUCCESS == PR_SetFDInheritable(writeStdout, true),
 115                      "couldn't set child stdout inheritable");
 116         PR_ProcessAttrSetStdioRedirect(pattr, PR_StandardOutput, writeStdout);
 117
 118         NS_ASSERTION(PR_SUCCESS == PR_CreatePipe(&readStderr, &writeStderr),
 119                      "couldn't create child stderr pipe");
 120         NS_ASSERTION(PR_SUCCESS == PR_SetFDInheritable(writeStderr, true),
 121                      "couldn't set child stderr inheritable");
 122         PR_ProcessAttrSetStdioRedirect(pattr, PR_StandardError, writeStderr);
 123
 124         // set up argv with test name to run
 125         char* const newArgv[3] = {
 126             strdup(sPathToThisBinary),
 127             strdup(aTestName),
 128             0
 129         };
 130
 131         // make sure the child will abort if an assertion fails
 132         NS_ASSERTION(PR_SUCCESS == PR_SetEnv(sAssertBehaviorEnv),
 133                      "couldn't set XPCOM_DEBUG_BREAK env var");
 134
 135         PRProcess* proc;
 136         NS_ASSERTION(proc = PR_CreateProcess(sPathToThisBinary,
 137                                              newArgv,
 138                                              0, // inherit environment
 139                                              pattr),
 140                      "couldn't create process");
 141         PR_Close(readStdin);
 142         PR_Close(writeStdout);
 143         PR_Close(writeStderr);
 144
 145         mProc = proc;
 146         mStdinfd = writeStdin;
 147         mStdoutfd = readStdout;
 148         mStderrfd = readStderr;
 149
 150         free(newArgv[0]);
 151         free(newArgv[1]);
 152         PR_DestroyProcessAttr(pattr);
 153     }
 154
 155     void RunToCompletion(uint32_t aWaitMs)
 156     {
 157         PR_Close(mStdinfd);
 158
 159         PRPollDesc pollfds[2];
 160         int32_t nfds;
 161         bool stdoutOpen = true, stderrOpen = true;
 162         char buf[4096];
 163         int32_t len;
 164
 165         PRIntervalTime now = PR_IntervalNow();
 166         PRIntervalTime deadline = now + PR_MillisecondsToInterval(aWaitMs);
 167
 168         while ((stdoutOpen || stderrOpen) && now < deadline) {
 169             nfds = 0;
 170             if (stdoutOpen) {
 171                 pollfds[nfds].fd = mStdoutfd;
 172                 pollfds[nfds].in_flags = PR_POLL_READ;
 173                 pollfds[nfds].out_flags = 0;
 174                 ++nfds;
 175             }
 176             if (stderrOpen) {
 177                 pollfds[nfds].fd = mStderrfd;
 178                 pollfds[nfds].in_flags = PR_POLL_READ;
 179                 pollfds[nfds].out_flags = 0;
 180                 ++nfds;
 181             }
 182
 183             int32_t rv = PR_Poll(pollfds, nfds, deadline - now);
 184             NS_ASSERTION(0 <= rv, PR_ErrorToName(PR_GetError()));
 185
 186             if (0 == rv) {      // timeout
 187                 fputs("(timed out!)\n", stderr);
 188                 Finish(false); // abnormal
 189                 return;
 190             }
 191
 192             for (int32_t i = 0; i < nfds; ++i) {
 193                 if (!pollfds[i].out_flags)
 194                     continue;
 195
 196                 bool isStdout = mStdoutfd == pollfds[i].fd;
 197
 198                 if (PR_POLL_READ & pollfds[i].out_flags) {
 199                     len = PR_Read(pollfds[i].fd, buf, sizeof(buf) - 1);
 200                     NS_ASSERTION(0 <= len, PR_ErrorToName(PR_GetError()));
 201                 }
 202                 else if (PR_POLL_HUP & pollfds[i].out_flags) {
 203                     len = 0;
 204                 }
 205                 else {
 206                     NS_ERROR(PR_ErrorToName(PR_GetError()));
 207                 }
 208
 209                 if (0 < len) {
 210                     buf[len] = '\0';
 211                     if (isStdout)
 212                         mStdout += buf;
 213                     else
 214                         mStderr += buf;
 215                 }
 216                 else if (isStdout) {
 217                     stdoutOpen = false;
 218                 }
 219                 else {
 220                     stderrOpen = false;
 221                 }
 222             }
 223
 224             now = PR_IntervalNow();
 225         }
 226
 227         if (stdoutOpen)
 228             fputs("(stdout still open!)\n", stderr);
 229         if (stderrOpen)
 230             fputs("(stderr still open!)\n", stderr);
 231         if (now > deadline)
 232             fputs("(timed out!)\n", stderr);
 233
 234         Finish(!stdoutOpen && !stderrOpen && now <= deadline);
 235     }
 236
 237 private:
 238     void Finish(bool normalExit) {
 239         if (!normalExit) {
 240             PR_KillProcess(mProc);
 241             mExitCode = -1;
 242             int32_t dummy;
 243             PR_WaitProcess(mProc, &dummy);
 244         }
 245         else {
 246             PR_WaitProcess(mProc, &mExitCode); // this had better not block ...
 247         }
 248
 249         PR_Close(mStdoutfd);
 250         PR_Close(mStderrfd);
 251     }
 252
 253     PRProcess* mProc;
 254     PRFileDesc* mStdinfd;         // writeable
 255     PRFileDesc* mStdoutfd;        // readable
 256     PRFileDesc* mStderrfd;        // readable
 257 };
 258
 259 //-----------------------------------------------------------------------------
 260 // Harness for checking detector errors
 261 bool
 262 CheckForDeadlock(const char* test, const char* const* findTokens)
 263 {
 264     Subprocess proc(test);
 265     proc.RunToCompletion(5000);
 266
 267     if (0 == proc.mExitCode)
 268         return false;
 269
 270     int32_t idx = 0;
 271     for (const char* const* tp = findTokens; *tp; ++tp) {
 272         const char* const token = *tp;
 273 #ifdef MOZILLA_INTERNAL_API
 274         idx = proc.mStderr.Find(token, false, idx);
 275 #else
 276         nsCString tokenCString(token);
 277         idx = proc.mStderr.Find(tokenCString, idx);
 278 #endif
 279         if (-1 == idx) {
 280             printf("(missed token '%s' in output)\n", token);
 281             puts("----------------------------------\n");
 282             puts(proc.mStderr.get());
 283             puts("----------------------------------\n");
 284             return false;
 285         }
 286         idx += strlen(token);
 287     }
 288
 289     return true;
 290 }
 291
 292 //-----------------------------------------------------------------------------
 293 // Single-threaded sanity tests
 294
 295 // Stupidest possible deadlock.
 296 int
 297 Sanity_Child()
 298 {
 299     TestMutex m1("dd.sanity.m1");
 300     m1.Lock();
 301     m1.Lock();
 302     return 0;                  // not reached
 303 }
 304
 305 nsresult
 306 Sanity()
 307 {
 308     const char* const tokens[] = {
 309         "###!!! ERROR: Potential deadlock detected",
 310         "=== Cyclical dependency starts at\n--- Mutex : dd.sanity.m1",
 311         "=== Cycle completed at\n--- Mutex : dd.sanity.m1",
 312         "###!!! Deadlock may happen NOW!", // better catch these easy cases...
 313         "###!!! ASSERTION: Potential deadlock detected",
 314         0
 315     };
 316     if (CheckForDeadlock("Sanity", tokens)) {
 317         PASS();
 318     } else {
 319         FAIL("deadlock not detected");
 320     }
 321 }
 322
 323 // Slightly less stupid deadlock.
 324 int
 325 Sanity2_Child()
 326 {
 327     TestMutex m1("dd.sanity2.m1");
 328     TestMutex m2("dd.sanity2.m2");
 329     m1.Lock();
 330     m2.Lock();
 331     m1.Lock();
 332     return 0;                  // not reached
 333 }
 334
 335 nsresult
 336 Sanity2()
 337 {
 338     const char* const tokens[] = {
 339         "###!!! ERROR: Potential deadlock detected",
 340         "=== Cyclical dependency starts at\n--- Mutex : dd.sanity2.m1",
 341         "--- Next dependency:\n--- Mutex : dd.sanity2.m2",
 342         "=== Cycle completed at\n--- Mutex : dd.sanity2.m1",
 343         "###!!! Deadlock may happen NOW!", // better catch these easy cases...
 344         "###!!! ASSERTION: Potential deadlock detected",
 345         0
 346     };
 347     if (CheckForDeadlock("Sanity2", tokens)) {
 348         PASS();
 349     } else {
 350         FAIL("deadlock not detected");
 351     }
 352 }
 353
 354
 355 int
 356 Sanity3_Child()
 357 {
 358     TestMutex m1("dd.sanity3.m1");
 359     TestMutex m2("dd.sanity3.m2");
 360     TestMutex m3("dd.sanity3.m3");
 361     TestMutex m4("dd.sanity3.m4");
 362
 363     m1.Lock();
 364     m2.Lock();
 365     m3.Lock();
 366     m4.Lock();
 367     m4.Unlock();
 368     m3.Unlock();
 369     m2.Unlock();
 370     m1.Unlock();
 371
 372     m4.Lock();
 373     m1.Lock();
 374     return 0;
 375 }
 376
 377 nsresult
 378 Sanity3()
 379 {
 380     const char* const tokens[] = {
 381         "###!!! ERROR: Potential deadlock detected",
 382         "=== Cyclical dependency starts at\n--- Mutex : dd.sanity3.m1",
 383         "--- Next dependency:\n--- Mutex : dd.sanity3.m2",
 384         "--- Next dependency:\n--- Mutex : dd.sanity3.m3",
 385         "--- Next dependency:\n--- Mutex : dd.sanity3.m4",
 386         "=== Cycle completed at\n--- Mutex : dd.sanity3.m1",
 387         "###!!! ASSERTION: Potential deadlock detected",
 388         0
 389     };
 390     if (CheckForDeadlock("Sanity3", tokens)) {
 391         PASS();
 392     } else {
 393         FAIL("deadlock not detected");
 394     }
 395 }
 396
 397
 398 int
 399 Sanity4_Child()
 400 {
 401     mozilla::ReentrantMonitor m1("dd.sanity4.m1");
 402     TestMutex m2("dd.sanity4.m2");
 403     m1.Enter();
 404     m2.Lock();
 405     m1.Enter();
 406     return 0;
 407 }
 408
 409 nsresult
 410 Sanity4()
 411 {
 412     const char* const tokens[] = {
 413         "Re-entering ReentrantMonitor after acquiring other resources",
 414         "###!!! ERROR: Potential deadlock detected",
 415         "=== Cyclical dependency starts at\n--- ReentrantMonitor : dd.sanity4.m1",
 416         "--- Next dependency:\n--- Mutex : dd.sanity4.m2",
 417         "=== Cycle completed at\n--- ReentrantMonitor : dd.sanity4.m1",
 418         "###!!! ASSERTION: Potential deadlock detected",
 419         0
 420     };
 421     if (CheckForDeadlock("Sanity4", tokens)) {
 422         PASS();
 423     } else {
 424         FAIL("deadlock not detected");
 425     }
 426 }
 427
 428 //-----------------------------------------------------------------------------
 429 // Multithreaded tests
 430
 431 TestMutex* ttM1;
 432 TestMutex* ttM2;
 433
 434 static void
 435 TwoThreads_thread(void* arg)
 436 {
 437     int32_t m1First = NS_PTR_TO_INT32(arg);
 438     if (m1First) {
 439         ttM1->Lock();
 440         ttM2->Lock();
 441         ttM2->Unlock();
 442         ttM1->Unlock();
 443     }
 444     else {
 445         ttM2->Lock();
 446         ttM1->Lock();
 447         ttM1->Unlock();
 448         ttM2->Unlock();
 449     }
 450 }
 451
 452 int
 453 TwoThreads_Child()
 454 {
 455     ttM1 = new TestMutex("dd.twothreads.m1");
 456     ttM2 = new TestMutex("dd.twothreads.m2");
 457     if (!ttM1 || !ttM2)
 458         NS_RUNTIMEABORT("couldn't allocate mutexes");
 459
 460     PRThread* t1 = spawn(TwoThreads_thread, (void*) 0);
 461     PR_JoinThread(t1);
 462
 463     PRThread* t2 = spawn(TwoThreads_thread, (void*) 1);
 464     PR_JoinThread(t2);
 465
 466     return 0;
 467 }
 468
 469 nsresult
 470 TwoThreads()
 471 {
 472     const char* const tokens[] = {
 473         "###!!! ERROR: Potential deadlock detected",
 474         "=== Cyclical dependency starts at\n--- Mutex : dd.twothreads.m2",
 475         "--- Next dependency:\n--- Mutex : dd.twothreads.m1",
 476         "=== Cycle completed at\n--- Mutex : dd.twothreads.m2",
 477         "###!!! ASSERTION: Potential deadlock detected",
 478         0
 479     };
 480
 481     if (CheckForDeadlock("TwoThreads", tokens)) {
 482         PASS();
 483     } else {
 484         FAIL("deadlock not detected");
 485     }
 486 }
 487
 488
 489 TestMutex* cndMs[4];
 490 const uint32_t K = 100000;
 491
 492 static void
 493 ContentionNoDeadlock_thread(void* arg)
 494 {
 495     int32_t starti = NS_PTR_TO_INT32(arg);
 496
 497     for (uint32_t k = 0; k < K; ++k) {
 498         for (int32_t i = starti; i < (int32_t) ArrayLength(cndMs); ++i)
 499             cndMs[i]->Lock();
 500         // comment out the next two lines for deadlocking fun!
 501         for (int32_t i = ArrayLength(cndMs) - 1; i >= starti; --i)
 502             cndMs[i]->Unlock();
 503
 504         starti = (starti + 1) % 3;
 505     }
 506 }
 507
 508 int
 509 ContentionNoDeadlock_Child()
 510 {
 511     PRThread* threads[3];
 512
 513     for (uint32_t i = 0; i < ArrayLength(cndMs); ++i)
 514         cndMs[i] = new TestMutex("dd.cnd.ms");
 515
 516     for (int32_t i = 0; i < (int32_t) ArrayLength(threads); ++i)
 517         threads[i] = spawn(ContentionNoDeadlock_thread, NS_INT32_TO_PTR(i));
 518
 519     for (uint32_t i = 0; i < ArrayLength(threads); ++i)
 520         PR_JoinThread(threads[i]);
 521
 522     for (uint32_t i = 0; i < ArrayLength(cndMs); ++i)
 523         delete cndMs[i];
 524
 525     return 0;
 526 }
 527
 528 nsresult
 529 ContentionNoDeadlock()
 530 {
 531     const char * func = __func__;
 532     Subprocess proc(func);
 533     proc.RunToCompletion(60000);
 534     if (0 != proc.mExitCode) {
 535         printf("(expected 0 == return code, got %d)\n", proc.mExitCode);
 536         puts("(output)\n----------------------------------\n");
 537         puts(proc.mStdout.get());
 538         puts("----------------------------------\n");
 539         puts("(error output)\n----------------------------------\n");
 540         puts(proc.mStderr.get());
 541         puts("----------------------------------\n");
 542
 543         FAIL("deadlock");
 544     }
 545     PASS();
 546 }
 547
 548
 549
 550 //-----------------------------------------------------------------------------
 551
 552 int
 553 main(int argc, char** argv)
 554 {
 555     if (1 < argc) {
 556         // XXX can we run w/o scoped XPCOM?
 557         const char* test = argv[1];
 558         ScopedXPCOM xpcom(test);
 559         if (xpcom.failed())
 560             return 1;
 561
 562         // running in a spawned process.  call the specificed child function.
 563         if (!strcmp("Sanity", test))
 564             return Sanity_Child();
 565         if (!strcmp("Sanity2", test))
 566             return Sanity2_Child();
 567         if (!strcmp("Sanity3", test))
 568             return Sanity3_Child();
 569         if (!strcmp("Sanity4", test))
 570             return Sanity4_Child();
 571
 572         if (!strcmp("TwoThreads", test))
 573             return TwoThreads_Child();
 574         if (!strcmp("ContentionNoDeadlock", test))
 575             return ContentionNoDeadlock_Child();
 576
 577         fail("%s | %s - unknown child test", __FILE__, __FUNCTION__);
 578         return 1;
 579     }
 580
 581     ScopedXPCOM xpcom("Storage deadlock detector correctness (" __FILE__ ")");
 582     if (xpcom.failed())
 583         return 1;
 584
 585     // in the first invocation of this process.  we will be the "driver".
 586     int rv = 0;
 587
 588     sPathToThisBinary = argv[0];
 589
 590     if (NS_FAILED(Sanity()))
 591         rv = 1;
 592     if (NS_FAILED(Sanity2()))
 593         rv = 1;
 594     if (NS_FAILED(Sanity3()))
 595         rv = 1;
 596     if (NS_FAILED(Sanity4()))
 597         rv = 1;
 598
 599     if (NS_FAILED(TwoThreads()))
 600         rv = 1;
 601     if (NS_FAILED(ContentionNoDeadlock()))
 602         rv = 1;
 603
 604     return rv;
 605 }