Add performance/profiling test (#424)

* Add performance/profiling test

Add test to perf_SUITE to do performance tests and also profile different activities in leveled.

This can then be used to highlight functions with unexpectedly high execution times, and prove the impact of changes.

Switch between riak_ctperf and riak_fullperf to change from standard test (with profile option) to full-scale performance test

* Change shape of default perfTest

* Change fullPerf

Change the fullPerf test to run more tests, but with fewer keys.

Given that RS of 512 is being pushed in Riak, 2M objects is till a 300M+ object cluster. 10M >> 1B.  so these are still reasonable sizes to test.

A profilePerf test also added to generate all the profiles base don 2M objects.

* Extend test

Queries where previously all returning a large number of index entries - changes made to make number of entries per query more realistic.  Also an update process added to show difference between loading and rotating keys.

* Relabel as AAE fold

* Test v5

Test mini-queries - where generally a small number of entries are returned

* Default to ctperf

src/leveled_imanifest.erl

@@ -19,7 +19,8 @@
         reader/2,
         writer/3,
         printer/1,
-        complete_filex/0
+        complete_filex/0,
+        get_cdbpids/1
         ]).         
 
 -define(MANIFEST_FILEX, "man").
@@ -218,6 +219,10 @@ from_list(Manifest) ->
     % reads are more common than stale reads
     lists:foldr(fun prepend_entry/2, [], Manifest).
 
+-spec get_cdbpids(manifest()) -> list(pid()).
+%% @doc return a list of PIDs within the manifest
+get_cdbpids(Manifest) ->
+    lists:map(fun(ME) -> element(3, ME) end, to_list(Manifest)).
 
 %%%============================================================================
 %%% Internal Functions

src/leveled_inker.erl

@@ -118,14 +118,20 @@
         ink_loglevel/2,
         ink_addlogs/2,
         ink_removelogs/2,
-        ink_getjournalsqn/1]).
+        ink_getjournalsqn/1,
+        ink_getcdbpids/1,
+        ink_getclerkpid/1
+    ]).
 
 -export([filepath/2, filepath/3]).
 
 -ifdef(TEST).
--export([build_dummy_journal/0, clean_testdir/1]).
+-export(
+    [build_dummy_journal/0, clean_testdir/1]
+).
 -endif.
 
+
 -define(MANIFEST_FP, "journal_manifest").
 -define(FILES_FP, "journal_files").
 -define(COMPACT_FP, "post_compact").
@@ -480,6 +486,19 @@ ink_removelogs(Pid, ForcedLogs) ->
 ink_getjournalsqn(Pid) ->
     gen_server:call(Pid, get_journalsqn, infinity).
 
+-spec ink_getcdbpids(pid()) -> list(pid()).
+%% @doc
+%% Used for profiling in tests - get a list of SST PIDs to profile
+ink_getcdbpids(Pid) ->
+    gen_server:call(Pid, get_cdbpids).
+
+-spec ink_getclerkpid(pid()) -> pid().
+%% @doc
+%% Used for profiling in tests - get the clerk PID to profile
+ink_getclerkpid(Pid) ->
+    gen_server:call(Pid, get_clerkpid).
+
+
 %%%============================================================================
 %%% gen_server callbacks
 %%%============================================================================
@@ -673,6 +692,11 @@ handle_call({check_sqn, LedgerSQN}, _From, State) ->
     end;
 handle_call(get_journalsqn, _From, State) ->
     {reply, {ok, State#state.journal_sqn}, State};
+handle_call(get_cdbpids, _From, State) ->
+    CDBPids = leveled_imanifest:get_cdbpids(State#state.manifest),
+    {reply, [State#state.active_journaldb|CDBPids], State};
+handle_call(get_clerkpid, _From, State) ->
+    {reply, State#state.clerk, State};
 handle_call(close, _From, State=#state{is_snapshot=Snap}) when Snap == true ->
     ok = ink_releasesnapshot(State#state.source_inker, self()),
     {stop, normal, ok, State};

src/leveled_penciller.erl

@@ -201,6 +201,8 @@
         sst_rootpath/1,
         sst_filename/3]).
 
+-export([pcl_getsstpids/1, pcl_getclerkpid/1]).
+
 -ifdef(TEST).
 -export([
         clean_testdir/1]).
@@ -614,6 +616,18 @@ pcl_addlogs(Pid, ForcedLogs) ->
 pcl_removelogs(Pid, ForcedLogs) ->
     gen_server:cast(Pid, {remove_logs, ForcedLogs}).
 
+-spec pcl_getsstpids(pid()) -> list(pid()).
+%% @doc
+%% Used for profiling in tests - get a list of SST PIDs to profile
+pcl_getsstpids(Pid) ->
+    gen_server:call(Pid, get_sstpids).
+
+-spec pcl_getclerkpid(pid()) -> pid().
+%% @doc
+%% Used for profiling in tests - get the clerk PID to profile
+pcl_getclerkpid(Pid) ->
+    gen_server:call(Pid, get_clerkpid).
+
 %%%============================================================================
 %%% gen_server callbacks
 %%%============================================================================
@@ -965,7 +979,11 @@ handle_call(check_for_work, _From, State) ->
     {_WL, WC} = leveled_pmanifest:check_for_work(State#state.manifest),
     {reply, WC > 0, State};
 handle_call(persisted_sqn, _From, State) ->
-    {reply, State#state.persisted_sqn, State}.
+    {reply, State#state.persisted_sqn, State};
+handle_call(get_sstpids, _From, State) ->
+    {reply, leveled_pmanifest:get_sstpids(State#state.manifest), State};
+handle_call(get_clerkpid, _From, State) ->
+    {reply, State#state.clerk, State}.
 
 handle_cast({manifest_change, Manifest}, State) ->
     NewManSQN = leveled_pmanifest:get_manifest_sqn(Manifest),

src/leveled_pmanifest.erl

@@ -46,7 +46,8 @@
         levelzero_present/1,
         check_bloom/3,
         report_manifest_level/2,
-        snapshot_pids/1
+        snapshot_pids/1,
+        get_sstpids/1
         ]).      
 
 -export([
@@ -699,6 +700,31 @@ check_bloom(Manifest, FP, Hash) ->
 snapshot_pids(Manifest) ->
     lists:map(fun(S) -> element(1, S) end, Manifest#manifest.snapshots).
 
+-spec get_sstpids(manifest()) -> list(pid()).
+%% @doc
+%% Return a list of all SST PIDs in the current manifest
+get_sstpids(Manifest) ->
+    FoldFun =
+        fun(I, Acc) ->
+            Level = array:get(I, Manifest#manifest.levels),
+            LevelAsList =
+                case I of
+                    I when I > 1 ->
+                        leveled_tree:to_list(Level);
+                    _ ->
+                        Level
+                end,
+            Pids =
+                lists:map(
+                    fun(MaybeME) ->
+                        ME = get_manifest_entry(MaybeME),
+                        ME#manifest_entry.owner
+                    end,
+                    LevelAsList),
+            Acc ++ Pids
+        end,
+    lists:foldl(FoldFun, [], lists:seq(0, Manifest#manifest.basement)).
+
 %%%============================================================================
 %%% Internal Functions
 %%%============================================================================

test/end_to_end/basic_SUITE.erl

@@ -14,7 +14,8 @@
             bigjournal_littlejournal/1,
             bigsst_littlesst/1,
             safereaderror_startup/1,
-            remove_journal_test/1
+            remove_journal_test/1,
+            bigpcl_bucketlist/1
             ]).
 
 all() -> [
@@ -30,7 +31,8 @@ all() -> [
             bigjournal_littlejournal,
             bigsst_littlesst,
             safereaderror_startup,
-            remove_journal_test
+            remove_journal_test,
+            bigpcl_bucketlist
             ].
 
 
@@ -1197,4 +1199,78 @@ safereaderror_startup(_Config) ->
     {ok, ReadBack} = leveled_bookie:book_get(Bookie2, B1, K1),
     io:format("Read back ~w", [ReadBack]),
     true = ReadBack == Obj2,
-    ok = leveled_bookie:book_close(Bookie2).
+    ok = leveled_bookie:book_close(Bookie2).
+
+bigpcl_bucketlist(_Config) ->
+    %% https://github.com/martinsumner/leveled/issues/326
+    %% In OTP 22+ there appear to be issues with anonymous functions which
+    %% have a reference to loop state, requiring a copy of all the loop state
+    %% to be made when returning the function.
+    %% This test creates  alarge loop state on the leveled_penciller to prove
+    %% this.
+    %% The problem can be resolved simply by renaming the element of the loop
+    %% state using within the anonymous function.
+    RootPath = testutil:reset_filestructure(),
+    BucketCount = 500,
+    ObjectCount = 100,
+    StartOpts1 = [{root_path, RootPath},
+                    {max_journalsize, 50000000},
+                    {cache_size, 4000},
+                    {max_pencillercachesize, 128000},
+                    {max_sstslots, 256},
+                    {sync_strategy, testutil:sync_strategy()}],
+    {ok, Bookie1} = leveled_bookie:book_start(StartOpts1),
+    BucketList =
+        lists:map(fun(I) -> list_to_binary(integer_to_list(I)) end,
+                    lists:seq(1, BucketCount)),
+
+    MapFun =
+        fun(B) ->
+            testutil:generate_objects(ObjectCount, 1, [], 
+                                        leveled_rand:rand_bytes(100), 
+                                        fun() -> [] end, 
+                                        B)
+        end,
+    ObjLofL = lists:map(MapFun, BucketList),
+    lists:foreach(fun(ObjL) -> testutil:riakload(Bookie1, ObjL) end, ObjLofL),
+    BucketFold =
+        fun(B, _K, _V, Acc) ->
+            case sets:is_element(B, Acc) of
+                true ->
+                    Acc;
+                false ->
+                    sets:add_element(B, Acc)
+            end
+        end,
+    FBAccT = {BucketFold, sets:new()},
+
+    {async, BucketFolder1} = 
+        leveled_bookie:book_headfold(Bookie1,
+                                        ?RIAK_TAG,
+                                        {bucket_list, BucketList},
+                                        FBAccT,
+                                        false, false, false),
+
+    {FoldTime1, BucketList1} = timer:tc(BucketFolder1, []),
+    true = BucketCount == sets:size(BucketList1),
+    ok = leveled_bookie:book_close(Bookie1),
+
+    {ok, Bookie2} = leveled_bookie:book_start(StartOpts1),
+
+    {async, BucketFolder2} = 
+        leveled_bookie:book_headfold(Bookie2,
+                                        ?RIAK_TAG,
+                                        {bucket_list, BucketList},
+                                        FBAccT,
+                                        false, false, false),
+    {FoldTime2, BucketList2} = timer:tc(BucketFolder2, []),
+    true = BucketCount == sets:size(BucketList2),
+
+    io:format("Fold pre-close ~w ms post-close ~w ms~n",
+                [FoldTime1 div 1000, FoldTime2 div 1000]),
+
+    true = FoldTime1 < 10 * FoldTime2,
+    %% The fold in-memory should be the same order of magnitude of response
+    %% time as the fold post-persistence
+
+    ok = leveled_bookie:book_destroy(Bookie2).