Skip to content

Instantly share code, notes, and snippets.

@alex-hhh alex-hhh/report.md
Created Jan 31, 2019

Embed
What would you like to do?
Racket CS performance testing using ActivityLog2

A Racket blog post was published recently outlining the performance of Racket-on-Chez implementation. There was a discussion on the racket-users list, which prompted me to do some testing of my own.

Testing overview

A while ago I wrote a profiler to analyze the performance of various ActivityLog2 subsystems and I used this to instrument some functions in to verify the time they take to run in Racket 7.1 versus Racket CS. The profiler wraps each function in code which times the duration of the function and records each call. The function times and number of calls can than be displayed later. The code for the profiler is available here

Two tests were updated, aggregate-test and fit-test, to display profile results at the end of their runs and these results were collected. Three Travis builds were run, each time Racket 7.1 and Racket CS were built in parallel.

The tests were run using the perf-test project branch and the sample build result is available on Travis. Unfortunately, Travis only shows the last build for a commit, so, even though the tests were run three times, only the last result is available from Travis.

Instrumented functions

  • df-histogram and df-mean-max are functions which only run Racket code, with no IO or calls into external libraries.

  • df-read/sql runs an SQL query and constructs a data frame from the result set (it runs query and converts the result from a list of vectors, one vector per row into a hash of vectors, one vector per data column returned by the query.

  • make-session-data-frame runs df-read/sql and than runs some Racket code to clean up the returned data and add some additional columns -- note that most columns are added lazily -- only a lambda is constructed which will construct the data when it is requested. The "raket only" time can be found by subtracting the df-read/sql time from make-session-data-frame time. In the tests below, there is one df-read/sql call for each make-session-data-frame

  • db-insert-activity walks a "tree" (an a-list of a-lists) and stores data in the database. It runs lots of SQL insert queries.

  • db-insert-activity-raw-data takes a "blob" of data, compresses it and inserts it into a database table.

  • db-import-activity-from-blob takes an activity file (FIT file) as a byte array, parses it into a "tree" (an a-list of a-lists) and calls db-insert-activity and db-insert-activity-raw-data. The parsing time is Racket only code and can be determined by subtracting the db-insert-activity and db-insert-activity-raw-data times.

  • check-session-df runs Racket only code

  • do-post-import-tasks runs a mixture of SQL queries and Racket code.

Overview of the tests

The tests were designed to check that the ActivityLog2 data processing operations work correctly. They are not performance tests, however, since they take a long time to run and they exercise actual application code, they can be useful in determining performance differences between Racket 7.1 and Racket CS.

  • aggregate-test is a test which calculates aggregate histograms and mean-maximal curves. For the performance testing purposes this test is useful because it runs the df-histogram and df-mean-max functions many times.

  • fit-test is a test which verifies that various fitness activity data files (FIT files) can be imported. For performance testing purposes this test is useful because it tests the performance of parsing binary files to construct large data structures and run lots of SQL operations -- note that this test runs against an in-memory SQLite database, so there is no disk IO for the SQL operations.

Some observations based on the collected data

Overall, the Racket CS implementation is slower than Racket 7.1 -- this seems to be the case for both code that is Racket only and does not perform any IO and it is also true for code that does IO:

  • df-histogram runs in approx the same time in 7.1 vs CS -- in some test runs it runs faster in 7.1 in others it is faster in CS.

  • df-mean-max is slower in Racket CS in all test runs -- this is one function I would love to make twice as fast :-)

  • df-read/sql runs faster in Racket CS.

  • db-insert-activity runs significantly slower in Racket CS

  • db-insert-activity-raw-data runs slower in Racket CS

  • make-session-data-frame w/o df-read/sql runs slower in Racket CS -- this is mostly Racket code -- there is still a small SQL statement, which returns 1 row of 2 values and should run fast.

  • It takes significantly longer in Racket CS to parse FIT files -- this is Racket code with takes a byte vector and constructs a tree (a-list of a-lists) This time is calculated as db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data time.

First Run

aggregate-test

Racket 7.1

                         calls       total         min         max        mean       stdev
df-histogram           :  2444     8866.74        0.06        51.3        3.63        2.65
df-mean-max            :  2778    74294.48        3.57      949.69       26.74       27.88
df-read/sql            :   282    16045.76        0.34      248.98        56.9       41.19
make-session-data-frame:   282    25716.25        3.04       377.8       91.19       63.26

make-session-data-frame w/o df-read/sql -- 9670.50

Racket CS

                         calls       total         min         max        mean       stdev
df-histogram           :  2444     9004.37        0.09       47.04        3.68        2.48
df-mean-max            :  2778    81112.23        3.89      155.53        29.2       17.02
df-read/sql            :   282    15902.05        0.35      782.05       56.39        58.2
make-session-data-frame:   282    28473.25        3.79      879.19      100.97       81.52

make-session-data-frame w/o df-read/sql -- 12571.20

fit-test

Racket 7.1

                              calls       total         min         max        mean       stdev
check-session-df            :    25      393.97        0.18      166.64       15.76        34.4
db-import-activity-from-blob:    23    48577.28       16.42    25676.72     2112.06     5232.63
db-insert-activity          :    23    28016.01        8.54       14503     1218.09     2951.17
db-insert-activity-raw-data :    23     2253.58        1.46     1095.32       97.98       229.9
df-histogram                :     0                                                            
df-mean-max                 :    13      551.61         0.1      414.21       42.43      107.75
df-read/sql                 :    25     4467.89        0.35     3057.11      178.72      592.16
do-post-import-tasks        :    21    32139.79       21.64    18056.81     1530.47     4005.36
make-session-data-frame     :    25     7444.44        3.53     4031.25      297.78      783.39

make-session-data-frame w/o df-read/sql -- 2976.55

db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data -- 18307.7

Racket CS

                              calls       total         min         max        mean       stdev
check-session-df            :    25      351.39         0.3      134.82       14.06        28.3
db-import-activity-from-blob:    23    69361.21       22.11    36713.33      3015.7      7525.6
db-insert-activity          :    23    42269.83       13.61    21996.49     1837.82     4511.16
db-insert-activity-raw-data :    23     3076.15        1.47     1513.67      133.75       317.8
df-histogram                :     0                                                            
df-mean-max                 :    13      570.84         0.1      431.34       43.91      112.27
df-read/sql                 :    25     3790.17        0.37     2461.16      151.61      476.31
do-post-import-tasks        :    21    38989.04       27.13    22238.92     1856.62     4909.28
make-session-data-frame     :    25      7483.4        4.31     3689.79      299.34      721.15

make-session-data-frame w/o df-read/sql -- 3693.23

db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data -- 24015.20

Second Run

aggregate-test

Racket 7.1

                         calls       total         min         max        mean       stdev
df-histogram           :  2444     9188.09        0.08       50.89        3.76         2.7
df-mean-max            :  2778    74908.75        3.61      544.64       26.96       21.19
df-read/sql            :   282    16312.02        0.37       245.1       57.84       42.09
make-session-data-frame:   282    27024.61        3.19       887.2       95.83       80.45

make-session-data-frame w/o df-read/sql -- 10712.60

Racket CS

                         calls       total         min         max        mean       stdev
df-histogram           :  2444     8931.29        0.08       39.24        3.65        2.44
df-mean-max            :  2778    80942.83         3.9      151.28       29.14       16.89
df-read/sql            :   282    15319.63        0.34       665.7       54.32        52.5
make-session-data-frame:   282    26736.35        3.59       730.7       94.81       73.93

make-session-data-frame w/o df-read/sql -- 11416.80

fit-test

Racket 7.1

                              calls       total         min         max        mean       stdev
check-session-df            :    25      406.11         0.2      176.42       16.24       35.97
db-import-activity-from-blob:    23     50085.8       15.64    26642.64     2177.64     5435.13
db-insert-activity          :    23    29248.77        8.59    15311.81     1271.69     3117.99
db-insert-activity-raw-data :    23     2260.84        1.42     1099.87        98.3      232.28
df-histogram                :     0                                                            
df-mean-max                 :    13      539.44        0.18      403.01        41.5       104.8
df-read/sql                 :    25     4657.41        0.35     3250.91       186.3       629.9
do-post-import-tasks        :    21    32658.95       13.62    18403.43     1555.19     4083.55
make-session-data-frame     :    25     7736.13        3.47     4248.61      309.45      825.84

make-session-data-frame w/o df-read/sql -- 3078.72

db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data -- 18576.20

Racket CS

                              calls       total         min         max        mean       stdev
check-session-df            :    25      347.82        0.28      142.15       13.91       29.37
db-import-activity-from-blob:    23    68672.85       21.48    36247.95     2985.78     7428.96
db-insert-activity          :    23    41672.97       13.81    21625.94     1811.87     4433.75
db-insert-activity-raw-data :    23     2993.43        1.43      1465.2      130.15      308.38
df-histogram                :     0                                                            
df-mean-max                 :    13      567.32        0.16      437.59       43.64       114.1
df-read/sql                 :    25     3612.98        0.35     2344.29      144.52      453.71
do-post-import-tasks        :    21    37158.91       22.73     21082.1     1769.47     4665.35
make-session-data-frame     :    25     7041.27        3.83      3464.8      281.65       677.5

make-session-data-frame w/o df-read/sql -- 3428.29

db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data -- 24006.50

Third Run

aggregate-test

Racket 7.1

                         calls       total         min         max        mean       stdev
df-histogram           :  2444     9432.81        0.09       77.13        3.86        2.98
df-mean-max            :  2778    76802.53         3.7      895.87       27.65       27.04
df-read/sql            :   282    16518.32        0.42       252.3       58.58       42.47
make-session-data-frame:   282    27465.39        3.71      944.25        97.4       82.54

make-session-data-frame w/o df-read/sql -- 10947.10

Racket CS

                         calls       total         min         max        mean       stdev
df-histogram           :  2444     8574.75        0.08       43.41        3.51        2.38
df-mean-max            :  2778    79444.73        3.88      142.63        28.6       16.52
df-read/sql            :   282    14843.43        0.37      221.77       52.64        37.9
make-session-data-frame:   282    27096.35        3.64      827.71       96.09       77.23

make-session-data-frame w/o df-read/sql -- 12253.00

fit-test

Racket 7.1

                              calls       total         min         max        mean       stdev
check-session-df            :    25      397.89        0.19      166.21       15.92       34.28
db-import-activity-from-blob:    23     51999.4       15.72    27271.61     2260.84     5615.93
db-insert-activity          :    23       29663        8.75    15487.53      1289.7     3175.67
db-insert-activity-raw-data :    23     2350.08        1.41     1129.64      102.18      240.29
df-histogram                :     0                                                            
df-mean-max                 :    13      559.86        0.11      419.73       43.07      109.15
df-read/sql                 :    25     4419.26        0.35      3015.7      176.77      584.15
do-post-import-tasks        :    21    32787.86       19.49    18309.56     1561.33     4073.08
make-session-data-frame     :    25     7418.88        3.57     3961.19      296.76      770.42

make-session-data-frame w/o df-read/sql 2999.62

db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data -- 19986.30

Racket CS

                              calls       total         min         max        mean       stdev
check-session-df            :    25       336.9        0.28      126.17       13.48       26.72
db-import-activity-from-blob:    23    69430.89       21.38    36854.99     3018.73     7549.78
db-insert-activity          :    23    41962.64          13    21854.75     1824.46     4479.33
db-insert-activity-raw-data :    23     3039.48        1.71     1492.76      132.15      313.72
df-histogram                :     0                                                            
df-mean-max                 :    13      575.83        0.24      438.25       44.29      114.16
df-read/sql                 :    25     3686.08        0.43     2401.16      147.44      464.84
do-post-import-tasks        :    21     38342.6       22.17     21982.3     1825.84     4855.82
make-session-data-frame     :    25     7111.39           4     3512.97      284.46      686.94

make-session-data-frame w/o df-read/sql -- 3425.31

db-import-activity-from-blob w/o db-insert-activity and db-insert-activity-raw-data -- 24428.80

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.