search

aprell / tasking-2.0

Tasking 2.0
16 stars 0 forks source link

Reductions benchmark #3

Open mratsim opened 4 years ago

mratsim commented 4 years ago

I wonder if you benched the reduction implementation or if you had benchmark to recommend?

I have implemented 2 benchmarks but it seems like reductions are as slow as serial. Actually lazy futures are even slower than the eager futures.

I suppose this is a either:

The 2-3 allocations: https://github.com/aprell/tasking-2.0/blob/303ce3e09a7c118241b9d5482219e3e3b848212e/src/runtime.c#L1525-L1545

Benchmark:

mratsim commented 4 years ago

Or it's the termination detection. profling shows that the workers are spending their time idling:

Note that a text vocabulary is often in the 50000-15000 words

Sanity check, logSumExp(1..<10) should be 9.4585514 (numpy logsumexp): 9.458551406860352

--------------------------------------------------------------------------
Scheduler:                                    Sequential
Benchmark:                                    Log-Sum-Exp (Machine Learning) 
Threads:                                      1
datasetSize:                                  20000
batchSize:                                    256
# of full batches:                            78
# of image labels:                            10
Text vocabulary size:                         1000
--------------------------------------------------------------------------
Dataset:                                      256x10
Time(ms):                                     65.479
Max RSS (KB):                                 97496
Runtime RSS (KB):                             0
# of page faults:                             0
Logsumexp:                                    994.2670288085938
--------------------------------------------------------------------------
Scheduler:                                    Weave (eager flowvars)
Benchmark:                                    Log-Sum-Exp (Machine Learning) 
Threads:                                      1
datasetSize:                                  20000
batchSize:                                    256
# of full batches:                            78
# of image labels:                            10
Text vocabulary size:                         1000
--------------------------------------------------------------------------
Dataset:                                      256x10
Time(ms):                                     308.294
Max RSS (KB):                                 97496
Runtime RSS (KB):                             0
# of page faults:                             342
Logsumexp:                                    994.2674560546875

+========================================+
|  Per-worker statistics                 |
+========================================+
  / use -d:WV_profile for high-res timers /  
Worker  3: 33 steal requests sent
Worker 10: 36 steal requests sent
Worker  3: 75 steal requests handled
Worker 10: 65 steal requests handled
Worker 29: 33 steal requests sent
Worker 27: 39 steal requests sent
Worker  8: 37 steal requests sent
Worker  8: 72 steal requests handled
Worker  8: 3421 steal requests declined
Worker  8: 5390 tasks executed
Worker  8: 72 tasks sent
Worker 10: 3436 steal requests declined
Worker  3: 3812 steal requests declined
Worker 10: 4988 tasks executed
Worker  6: 31 steal requests sent
Worker 22: 33 steal requests sent
Worker 22: 0 steal requests handled
Worker 22: 2576 steal requests declined
Worker 22: 16986 tasks executed
Worker 22: 0 tasks sent
Worker 22: 0 tasks split
Worker 22: 100.00 % steal-one
Worker 22: 0.00 % steal-half
Timer,22,70.254,6998.741,3451.635,0.622,17846.474,28367.727
Worker 17: 38 steal requests sent
Worker 17: 38 steal requests handled
Worker 17: 2784 steal requests declined
Worker 31: 34 steal requests sent
Worker 31: 0 steal requests handled
Worker 31: 2052 steal requests declined
Worker 26: 38 steal requests sent
Worker 19: 34 steal requests sent
Worker 19: 0 steal requests handled
Worker 19: 2713 steal requests declined
Worker 19: 23280 tasks executed
Worker 19: 0 tasks sent
Worker 19: 0 tasks split
Worker 19: 100.00 % steal-one
Worker 19: 0.00 % steal-half
Timer,19,131.721,7056.739,3433.744,1.068,17743.030,28366.303
Worker 28: 36 steal requests sent
Worker 28: 0 steal requests handled
Worker 28: 2537 steal requests declined
Worker 28: 24649 tasks executed
Worker 28: 0 tasks sent
Worker 28: 0 tasks split
Worker 28: 100.00 % steal-one
Worker 28: 0.00 % steal-half
Timer,28,114.383,7038.537,3418.580,0.956,17730.621,28303.077
Worker 32: 34 steal requests sent
Worker 32: 0 steal requests handled
Worker 32: 2082 steal requests declined
Worker 32: 9079 tasks executed
Worker 32: 0 tasks sent
Worker 32: 0 tasks split
Worker 32: 100.00 % steal-one
Worker 32: 0.00 % steal-half
Timer,32,56.943,6957.737,3399.172,0.462,17981.132,28395.446
Worker 13: 37 steal requests sent
Worker 13: 73 steal requests handled
Worker 13: 3006 steal requests declined
Worker 13: 8252 tasks executed
Worker 13: 73 tasks sent
Worker 13: 73 tasks split
Worker 13: 100.00 % steal-one
Worker 13: 0.00 % steal-half
Timer,13,147.470,7099.723,3438.656,2.372,17740.460,28428.681
Worker  8: 72 tasks split
Worker  8: 100.00 % steal-one
Worker 30: 37 steal requests sent
Worker 30: 0 steal requests handled
Worker 30: 2444 steal requests declined
Worker 30: 23325 tasks executed
Worker 30: 0 tasks sent
Worker 30: 0 tasks split
Worker 30: 100.00 % steal-one
Worker 30: 0.00 % steal-half
Timer,30,94.372,7038.752,3446.618,0.785,17766.724,28347.251
Worker 16: 38 steal requests sent
Worker 16: 72 steal requests handled
Worker 16: 2655 steal requests declined
Worker 16: 3708 tasks executed
Worker 16: 72 tasks sent
Worker 16: 72 tasks split
Worker 16: 100.00 % steal-one
Worker 16: 0.00 % steal-half
Timer,16,86.647,8105.503,3231.686,2.798,18223.436,29650.070
Worker  9: 34 steal requests sent
Worker  9: 64 steal requests handled
Worker  9: 3274 steal requests declined
Worker  9: 25721 tasks executed
Worker  9: 64 tasks sent
Worker  9: 64 tasks split
Worker  9: 100.00 % steal-one
Worker  9: 0.00 % steal-half
Timer,9,249.162,7092.431,3436.262,2.427,17734.208,28514.490
Worker  7: 40 steal requests sent
Worker  7: 74 steal requests handled
Worker  7: 3191 steal requests declined
Worker  7: 5327 tasks executed
Worker  7: 74 tasks sent
Worker  7: 74 tasks split
Worker  7: 100.00 % steal-one
Worker  7: 0.00 % steal-half
Timer,7,138.054,6861.554,3482.237,3.287,17315.058,27800.189
Worker 24: 33 steal requests sent
Worker 24: 0 steal requests handled
Worker 24: 2418 steal requests declined
Worker 24: 25174 tasks executed
Worker 24: 0 tasks sent
Worker 24: 0 tasks split
Worker 24: 100.00 % steal-one
Worker 24: 0.00 % steal-half
Timer,24,99.328,7045.619,3415.327,0.815,17725.872,28286.961
Worker  3: 26724 tasks executed
Worker  3: 75 tasks sent
Worker  3: 75 tasks split
Worker  3: 100.00 % steal-one
Worker 15: 38 steal requests sent
Worker 15: 66 steal requests handled
Worker 15: 2646 steal requests declined
Worker 15: 2726 tasks executed
Worker  6: 70 steal requests handled
Worker  6: 3555 steal requests declined
Worker  6: 26274 tasks executed
Worker  6: 70 tasks sent
Worker  6: 70 tasks split
Worker  6: 100.00 % steal-one
Worker  6: 0.00 % steal-half
Timer,6,196.350,6996.878,3429.454,2.007,17719.904,28344.594
Worker 14: 35 steal requests sent
Worker 14: 68 steal requests handled
Worker 14: 3072 steal requests declined
Worker 14: 4599 tasks executed
Worker 14: 68 tasks sent
Worker 14: 68 tasks split
Worker 14: 100.00 % steal-one
Worker 14: 0.00 % steal-half
Timer,14,162.134,7116.283,3409.806,2.232,17722.834,28413.289
Worker  1: 20 steal requests sent
Worker  1: 60 steal requests handled
Worker  1: 4363 steal requests declined
Worker  1: 51445 tasks executed
Worker  1: 60 tasks sent
Worker  1: 60 tasks split
Worker  1: 100.00 % steal-one
Worker  1: 0.00 % steal-half
Timer,1,299.332,7030.355,3396.620,4.260,17656.248,28386.814
Worker 27: 0 steal requests handled
Worker 27: 2303 steal requests declined
Worker 27: 17857 tasks executed
Worker 27: 0 tasks sent
Worker 27: 0 tasks split
Worker 27: 100.00 % steal-one
Worker 27: 0.00 % steal-half
Timer,27,71.999,7034.148,3428.589,0.547,17731.467,28266.751
Worker  0: 1 steal requests sent
Worker  0: 40 steal requests handled
Worker  0: 5045 steal requests declined
Worker  0: 2473159 tasks executed
Worker  0: 40 tasks sent
Worker  0: 10 tasks split
Worker  0: 100.00 % steal-one
Worker  0: 0.00 % steal-half
Timer,0,7428.066,5852.005,2049.953,7.784,11052.187,26389.995
Worker 21: 34 steal requests sent
Worker 21: 0 steal requests handled
Worker 21: 2869 steal requests declined
Worker 21: 23934 tasks executed
Worker 21: 0 tasks sent
Worker 21: 0 tasks split
Worker 21: 100.00 % steal-one
Worker 21: 0.00 % steal-half
Timer,21,141.978,7028.810,3428.964,1.293,17726.939,28327.984
Worker 31: 8281 tasks executed
Worker 31: 0 tasks sent
Worker 31: 0 tasks split
Worker 31: 100.00 % steal-one
Worker 31: 0.00 % steal-half
Timer,31,42.433,7075.626,3462.089,0.381,17755.089,28335.618
Worker 12: 36 steal requests sent
Worker 12: 74 steal requests handled
Worker 12: 3042 steal requests declined
Worker 12: 7046 tasks executed
Worker 12: 74 tasks sent
Worker 12: 74 tasks split
Worker 12: 100.00 % steal-one
Worker 12: 0.00 % steal-half
Timer,12,163.312,7059.514,3404.781,2.375,17686.628,28316.610
Worker 25: 38 steal requests sent
Worker 25: 0 steal requests handled
Worker 25: 2506 steal requests declined
Worker 25: 28919 tasks executed
Worker 25: 0 tasks sent
Worker 25: 0 tasks split
Worker 25: 100.00 % steal-one
Worker 25: 0.00 % steal-half
Timer,25,111.899,7063.668,3431.609,0.838,17721.555,28329.568
Worker  3: 0.00 % steal-half
Timer,3,228.089,7106.528,3406.020,3.824,17689.052,28433.513
Worker 15: 66 tasks sent
Worker 15: 66 tasks split
Worker 15: 100.00 % steal-one
Worker 15: 0.00 % steal-half
Timer,15,80.058,7134.656,3520.893,1.772,17707.194,28444.574
Worker 35: 39 steal requests sent
Worker 35: 0 steal requests handled
Worker 35: 2323 steal requests declined
Worker 35: 12824 tasks executed
Worker 35: 0 tasks sent
Worker 35: 0 tasks split
Worker 35: 100.00 % steal-one
Worker 35: 0.00 % steal-half
Timer,35,90.430,7100.583,3427.469,0.761,17772.149,28391.392
Worker  2: 21 steal requests sent
Worker  2: 60 steal requests handled
Worker  2: 4195 steal requests declined
Worker  2: 54829 tasks executed
Worker  2: 60 tasks sent
Worker  2: 60 tasks split
Worker  2: 100.00 % steal-one
Worker  2: 0.00 % steal-half
Timer,2,14854.437,7780.487,3028.948,2.399,15690.848,41357.119
Worker 18: 36 steal requests sent
Worker 18: 0 steal requests handled
Worker 18: 2885 steal requests declined
Worker 18: 25927 tasks executed
Worker 18: 0 tasks sent
Worker 18: 0 tasks split
Worker 18: 100.00 % steal-one
Worker 18: 0.00 % steal-half
Timer,18,140.243,7082.420,3414.857,1.215,17653.338,28292.073
Worker 26: 0 steal requests handled
Worker 26: 2429 steal requests declined
Worker 26: 20008 tasks executed
Worker  4: 29 steal requests sent
Worker  4: 67 steal requests handled
Worker  4: 3860 steal requests declined
Worker  4: 28989 tasks executed
Worker  4: 67 tasks sent
Worker  4: 67 tasks split
Worker  4: 100.00 % steal-one
Worker  4: 0.00 % steal-half
Timer,4,250.399,6385.547,4857.116,3.763,18666.364,30163.189
Worker 33: 37 steal requests sent
Worker 33: 0 steal requests handled
Worker 33: 2157 steal requests declined
Worker 20: 32 steal requests sent
Worker 20: 0 steal requests handled
Worker 11: 34 steal requests sent
Worker 11: 63 steal requests handled
Worker 11: 3035 steal requests declined
Worker 11: 7328 tasks executed
Worker 10: 65 tasks sent
Worker 10: 65 tasks split
Worker 10: 100.00 % steal-one
Worker 10: 0.00 % steal-half
Timer,10,195.228,7119.545,3418.841,2.004,17733.731,28469.349
Worker 17: 8194 tasks executed
Worker 26: 0 tasks sent
Worker 26: 0 tasks split
Worker 26: 100.00 % steal-one
Worker 26: 0.00 % steal-half
Timer,26,96.546,7063.857,3403.231,0.741,17724.032,28288.407
Worker 20: 2558 steal requests declined
Worker 20: 19716 tasks executed
Worker 20: 0 tasks sent
Worker 20: 0 tasks split
Worker  8: 0.00 % steal-half
Timer,8,192.811,7093.305,3423.944,3.574,17710.355,28423.989
Worker  5: 31 steal requests sent
Worker  5: 68 steal requests handled
Worker  5: 3545 steal requests declined
Worker 34: 37 steal requests sent
Worker 34: 0 steal requests handled
Worker 17: 38 tasks sent
Worker 17: 38 tasks split
Worker 17: 100.00 % steal-one
Worker 17: 0.00 % steal-half
Timer,17,99.339,7057.996,3440.329,1.072,17737.308,28336.044
Worker  5: 30440 tasks executed
Worker  5: 68 tasks sent
Worker  5: 68 tasks split
Worker 34: 2159 steal requests declined
Worker  5: 100.00 % steal-one
Worker 29: 0 steal requests handled
Worker 29: 2449 steal requests declined
Worker 29: 20583 tasks executed
Worker 29: 0 tasks sent
Worker 29: 0 tasks split
Worker 29: 100.00 % steal-one
Worker 29: 0.00 % steal-half
Timer,29,98.517,7055.290,3405.382,0.825,17710.874,28270.887
Worker 11: 63 tasks sent
Worker 11: 63 tasks split
Worker 11: 100.00 % steal-one
Worker 11: 0.00 % steal-half
Timer,11,14759.737,7823.362,3037.788,2.207,15743.915,41367.009
Worker  5: 0.00 % steal-half
Timer,5,14806.778,12367.326,3971.878,2.673,18949.675,50098.329
Worker 20: 100.00 % steal-one
Worker 20: 0.00 % steal-half
Worker 34: 11318 tasks executed
Worker 34: 0 tasks sent
Worker 34: 0 tasks split
Worker 34: 100.00 % steal-one
Worker 34: 0.00 % steal-half
Timer,34,64.704,7063.165,3421.925,0.553,17726.712,28277.060
Timer,20,104.570,7041.677,3411.791,0.815,17711.852,28270.705
Worker 33: 11421 tasks executed
Worker 33: 0 tasks sent
Worker 33: 0 tasks split
Worker 33: 100.00 % steal-one
Worker 33: 0.00 % steal-half
Timer,33,58.339,7072.869,3413.858,0.470,17742.986,28288.522
Worker 23: 32 steal requests sent
Worker 23: 0 steal requests handled
Worker 23: 2379 steal requests declined
Worker 23: 21580 tasks executed
Worker 23: 0 tasks sent
Worker 23: 0 tasks split
Worker 23: 100.00 % steal-one
Worker 23: 0.00 % steal-half
Timer,23,83.116,2767.684,9312.722,0.729,24085.002,36249.252
+========================================+
mratsim commented 4 years ago

Further investigation (and fixes to the benchmark) shows that it's actually faster than serial except when the number of threads = number of logical cores.

Repeated multiple times

beta ~/Programming/Nim/weave [master] $  WEAVE_NUM_THREADS=36 perf stat ./build/lse
Note that a text vocabulary is often in the 50000-15000 words

Sanity check, logSumExp(1..<10) should be 9.4585514 (numpy logsumexp): 9.458551406860352

--------------------------------------------------------------------------
Scheduler:                                    Weave (eager flowvars)
Benchmark:                                    Log-Sum-Exp (Machine Learning) 
Threads:                                      36
datasetSize:                                  20000
batchSize:                                    256
# of full batches:                            78
# of image labels:                            1000
Text vocabulary size:                         10000
--------------------------------------------------------------------------
Dataset:                                      256x1000
Time(ms):                                     228.487
Max RSS (KB):                                 81604
Runtime RSS (KB):                             0
# of page faults:                             197
Logsumexp:                                    1013.554077148438

 Performance counter stats for './build/lse':

         14,488.91 msec task-clock                #   31.170 CPUs utilized          
             1,289      context-switches          #    0.089 K/sec                  
                36      cpu-migrations            #    0.002 K/sec                  
            20,935      page-faults               #    0.001 M/sec                  
    58,161,673,679      cycles                    #    4.014 GHz                    
   103,899,165,199      instructions              #    1.79  insn per cycle         
    24,780,142,839      branches                  # 1710.283 M/sec                  
           578,719      branch-misses             #    0.00% of all branches        

       0.464831630 seconds time elapsed

      14.440058000 seconds user
       0.046503000 seconds sys

beta ~/Programming/Nim/weave [master] $  WEAVE_NUM_THREADS=35 perf stat ./build/lse
Note that a text vocabulary is often in the 50000-15000 words

Sanity check, logSumExp(1..<10) should be 9.4585514 (numpy logsumexp): 9.458551406860352

--------------------------------------------------------------------------
Scheduler:                                    Weave (eager flowvars)
Benchmark:                                    Log-Sum-Exp (Machine Learning) 
Threads:                                      35
datasetSize:                                  20000
batchSize:                                    256
# of full batches:                            78
# of image labels:                            1000
Text vocabulary size:                         10000
--------------------------------------------------------------------------
Dataset:                                      256x1000
Time(ms):                                     35.996
Max RSS (KB):                                 86684
Runtime RSS (KB):                             5212
# of page faults:                             1554
Logsumexp:                                    1013.553344726562

 Performance counter stats for './build/lse':

          5,438.80 msec task-clock                #   31.445 CPUs utilized          
               683      context-switches          #    0.126 K/sec                  
                35      cpu-migrations            #    0.006 K/sec                  
            22,251      page-faults               #    0.004 M/sec                  
    21,215,582,401      cycles                    #    3.901 GHz                    
    36,884,674,954      instructions              #    1.74  insn per cycle         
     8,670,096,363      branches                  # 1594.120 M/sec                  
           914,641      branch-misses             #    0.01% of all branches        

       0.172962317 seconds time elapsed

       5.389163000 seconds user
       0.050826000 seconds sys
aprell commented 4 years ago

I probably forgot to mention that this is nothing more than a first attempt at splitting tasks with return values. I realized that splittable futures could be used to support reductions, so I tried that, without worrying about algorithmic inefficiencies. To be honest, I'm not sure if this approach is salvageable – unless you manage to transform it into a tree-like reduction. 

mratsim commented 4 years ago

I see, then I will scrap it for now, however I may reuse that notify of data dependencies: https://github.com/mratsim/weave/issues/31

For matrix multiplication and nested for loops, I need a barrier that works also for worker threads or even better a way to specify data dependencies like I need the task with range [i, i+64] ready to continue. Similar to OpenMP: image

So I was thinking that I should implement reduction first and then see how they manage data dependencies and then use a similar techniques. Back to the drawing board, and I guess I'll start first with a worker barrier.

mratsim commented 4 years ago

So it turned out that I didn't split tasks in "loadBalance"/RT_Poll which meant that in parallel for loop that didn't generate any task I was basically doing measuring my sequential performance with runtime overhead sprinkled on top.

The reduce technique is actually not bad on eager futures though I'm worried with lazy futures as they need to allocate 3 times instead of 2 times for the eager ones, see https://github.com/mratsim/weave/pull/83.