X Debugging tokudb TRY_AGAIN

storage/tokudb/PerconaFT/ft/ft-ops.cc

@@ -3372,6 +3372,8 @@ unlock_ftnode_fun (void *v) {
 }
 
 /* search in a node's child */
+static __thread uint again_pin_forq;
+
 static int
 ft_search_child(FT_HANDLE ft_handle, FTNODE node, int childnum, ft_search *search, FT_GET_CALLBACK_FUNCTION getf, void *getf_v, bool *doprefetch, FT_CURSOR ftcursor, UNLOCKERS unlockers,
                  ANCESTORS ancestors, const pivot_bounds &bounds, bool can_bulk_fetch)
@@ -3407,6 +3409,7 @@ ft_search_child(FT_HANDLE ft_handle, FTNODE node, int childnum, ft_search *searc
                                          &childnode,
                                          &msgs_applied);
         if (rr==TOKUDB_TRY_AGAIN) {
+            again_pin_forq++;
             return rr;
         }
         invariant_zero(rr);
@@ -3546,6 +3549,9 @@ static bool search_try_again(FTNODE node, int child_to_search, ft_search *search
     return try_again;
 }
 
+static __thread uint again_ftsearch_h0, again_ftsearch_h123, again_getf, again_search_tryagain;
+static __thread uint xxx_ftsearch_err, xxx_getf_ok, xxx_getf_err;
+
 static int
 ft_search_node(
     FT_HANDLE ft_handle,
@@ -3603,6 +3609,16 @@ ft_search_node(
     }
 
     if (r != DB_NOTFOUND) {
+        if (r == TOKUDB_TRY_AGAIN) {
+            if (node->height > 0)
+                again_ftsearch_h123++;
+            else
+                again_ftsearch_h0++;
+            //fprintf(stderr, "(1) ft_search_* -> TRY_AGAIN\n");
+        }
+        else {
+            xxx_ftsearch_err++;
+        }
         return r; //Error (or message to quit early, such as TOKUDB_FOUND_BUT_REJECTED or TOKUDB_TRY_AGAIN)
     }
     // not really necessary, just put this here so that reading the
@@ -3617,8 +3633,17 @@ ft_search_node(
         if (pivot != nullptr) {
             int rr = getf(pivot->size, pivot->data, 0, nullptr, getf_v, true);
             if (rr != 0) {
+                if (rr == TOKUDB_TRY_AGAIN) {
+                    again_getf++;
+                    //fprintf(stderr, "(2) getf -> TRY_AGAIN\n");
+                }
+                else {
+                    xxx_getf_err++;
+                }
                 return rr; // lock was not granted
             }
+
+            xxx_getf_ok++;
         }
     }
 
@@ -3635,22 +3660,33 @@ ft_search_node(
     // because there is no guarantee that messages have been applied
     // on any other path.
     if (search_try_again(node, child_to_search, search)) {
+        //fprintf(stderr, "(3) search_try_again -> TRY_AGAIN\n");
+        again_search_tryagain++;
         r = TOKUDB_TRY_AGAIN;
     }
 
     return r;
 }
 
+static __thread uint in_toku_ft_search;
+
 int toku_ft_search(FT_HANDLE ft_handle, ft_search *search, FT_GET_CALLBACK_FUNCTION getf, void *getf_v, FT_CURSOR ftcursor, bool can_bulk_fetch)
 // Effect: Perform a search.  Associate cursor with a leaf if possible.
 // All searches are performed through this function.
 {
     int r;
+    static uint n_noretry;
     uint trycount = 0;     // How many tries did it take to get the result?
     FT ft = ft_handle->ft;
 
     toku::context search_ctx(CTX_SEARCH);
 
+    uint my_n_toku_ft_search = in_toku_ft_search++;
+
+    again_ftsearch_h0 = again_ftsearch_h123 = again_getf = again_search_tryagain = 0;
+    again_pin_forq = 0;
+    xxx_ftsearch_err = xxx_getf_ok = xxx_getf_err = 0;
+
 try_again:
 
     trycount++;
@@ -3760,6 +3796,7 @@ try_again:
     {   // accounting (to detect and measure thrashing)
         uint retrycount = trycount - 1;         // how many retries were needed?
         if (retrycount) {
+            //fprintf(stderr, "AAA %u\n", retrycount);
             FT_STATUS_INC(FT_TOTAL_RETRIES, retrycount);
         }
         if (retrycount > tree_height) {         // if at least one node was read from disk more than once
@@ -3768,6 +3805,17 @@ try_again:
                 FT_STATUS_INC(FT_SEARCH_TRIES_GT_HEIGHTPLUS3, 1);
         }
     }
+    if (trycount <= 5)
+        n_noretry++;
+    else {
+        //fprintf(stderr, "toku_ft_search trycount: %u\t(#ftsearch: %u\t#getf: %u#search with #retry ~= 0: %u)\n", trycount, n_noretry);
+        fprintf(stderr, "toku_ft_search trycount: %u\trec.depth: %u\n", trycount, in_toku_ft_search - my_n_toku_ft_search);
+        fprintf(stderr, "\t#ftsearch:\t\t%u\t(#h0: %u, #h>0: %u, #ftsearch_err: %u)\n",
+            again_ftsearch_h0 + again_ftsearch_h123, again_ftsearch_h0, again_ftsearch_h123, xxx_ftsearch_err);
+        fprintf(stderr, "\t\t#again_pin_forq: %u\n", again_pin_forq);
+        fprintf(stderr, "\t#getf:\t\t\t%u\t(#getf_ok: %u\t#getf_err: %u)\n", again_getf, xxx_getf_ok, xxx_getf_err);
+        fprintf(stderr, "\t#search_tryagain:\t%u\n", again_search_tryagain);
+    }
     return r;
 }
 

storage/tokudb/PerconaFT/tools/ftverify.cc

@@ -54,6 +54,7 @@ Copyright (c) 2006, 2015, Percona and/or its affiliates. All rights reserved.
 #include "ft/serialize/rbuf.h"
 #include "ft/serialize/sub_block.h"
 #include "util/threadpool.h"
+#include "util/scoped_malloc.h"
 
 #include <fcntl.h>
 #include <math.h>
@@ -410,6 +411,8 @@ main(int argc, char const * const argv[])
         assert(pct > 0.0 && pct <= 100.0);
     }
 
+    toku_scoped_malloc_init();
+
     // Open the file as read-only.
     dictfd = open(dictfname, O_RDONLY | O_BINARY, S_IRWXU | S_IRWXG | S_IRWXO);
     if (dictfd < 0) {