Time optimizations

.gitignore

 bin
 out
-progs/*.txt
+progs/*-actual.txt
+progs/*-expected.txt
+progs/*-time.csv

.gitlab-ci.yml

-asmgen:
-    script: "/testers/cs24/project03/asmgen/test"
+compiler:
+    script: "/testers/cs24/project02/compiler/test"

Makefile

 CC = clang-with-asan
-CFLAGS = -Iinclude -Wall -Wextra
+CFLAGS = -Iinclude -Wall -Wextra -fno-sanitize=integer
 ASM = clang
 
-TESTS_1 =            $(sort $(wildcard progs/stage1-*.bas))
-TESTS_2 = $(TESTS_1) $(sort $(wildcard progs/stage2-*.bas))
-TESTS_3 = $(TESTS_2) $(sort $(wildcard progs/stage3-*.bas))
-TESTS_4 = $(TESTS_3) $(sort $(wildcard progs/stage4-*.bas))
-TESTS_5 = $(TESTS_4) $(sort $(wildcard progs/stage5-*.bas))
-TESTS_6 = $(TESTS_5) $(sort $(wildcard progs/stage6-*.bas))
-TESTS_7 = $(TESTS_6) $(sort $(wildcard progs/stage7-*.bas))
-
-test: test7
-test1: $(TESTS_1:progs/%.bas=%-result)
-test2: $(TESTS_2:progs/%.bas=%-result)
-test3: $(TESTS_3:progs/%.bas=%-result)
-test4: $(TESTS_4:progs/%.bas=%-result)
-test5: $(TESTS_5:progs/%.bas=%-result)
-test6: $(TESTS_6:progs/%.bas=%-result)
-test7: $(TESTS_7:progs/%.bas=%-result)
+COMPILE_TESTS_1 =                    $(sort $(wildcard progs/stage1-*.bas))
+COMPILE_TESTS_2 = $(COMPILE_TESTS_1) $(sort $(wildcard progs/stage2-*.bas))
+COMPILE_TESTS_3 = $(COMPILE_TESTS_2) $(sort $(wildcard progs/stage3-*.bas))
+COMPILE_TESTS_4 = $(COMPILE_TESTS_3) $(sort $(wildcard progs/stage4-*.bas))
+COMPILE_TESTS_5 = $(COMPILE_TESTS_4) $(sort $(wildcard progs/stage5-*.bas))
+COMPILE_TESTS_6 = $(COMPILE_TESTS_5) $(sort $(wildcard progs/stage6-*.bas))
+COMPILE_TESTS_7 = $(COMPILE_TESTS_6) $(sort $(wildcard progs/stage7-*.bas))
+
+OPT_TESTS_1 = stage7-unhash
+OPT_TESTS_2 = stage7-loops-of-ops
+
+all: compile opt1 opt2
+
+compile: compile7
+compile1: $(COMPILE_TESTS_1:progs/%.bas=%-result)
+compile2: $(COMPILE_TESTS_2:progs/%.bas=%-result)
+compile3: $(COMPILE_TESTS_3:progs/%.bas=%-result)
+compile4: $(COMPILE_TESTS_4:progs/%.bas=%-result)
+compile5: $(COMPILE_TESTS_5:progs/%.bas=%-result)
+compile6: $(COMPILE_TESTS_6:progs/%.bas=%-result)
+compile7: $(COMPILE_TESTS_7:progs/%.bas=%-result)
+
+opt1: $(OPT_TESTS_1:=-bench)
+opt2: $(OPT_TESTS_2:=-bench)
 
 out/%.o: src/%.c
-	$(CC) $(CFLAGS) -c $< -o $@
+	$(CC) $(CFLAGS) -c $^ -o $@
+
+out/%.o: runtime/%.c
+	$(ASM) $(CFLAGS) -O3 -c $^ -o $@
 
 bin/compiler: out/ast.o out/compile.o out/compiler.o out/parser.o
 	$(CC) $(CFLAGS) $^ -o $@
@@ -28,21 +39,31 @@ bin/compiler: out/ast.o out/compile.o out/compiler.o out/parser.o
 out/%.s: progs/%.bas bin/compiler
 	bin/compiler $< > $@
 
-bin/%: out/%.s call-check.s
-	$(ASM) -g -Wl,--entry=check_start -nostartfiles $^ -o $@
+bin/%: out/%.s out/print_int.o runtime/call_check.s
+	$(ASM) -g -nostartfiles $^ -o $@
+
+bin/time-%: out/%.s out/print_int_mock.o out/timing.o
+	$(ASM) -lm $^ -o $@
 
 progs/%-expected.txt: progs/%.bas
-	grep '^#' $< | sed -e 's/#//' > $@
+	grep '^#' $^ | sed -e 's/#//' > $@
 
 progs/%-actual.txt: bin/%
-	$< > $@
+	$^ > $@
 
 %-result: progs/%-expected.txt progs/%-actual.txt
 	diff -u $^ \
 		&& echo PASSED test $(@F:-result=). \
 		|| (echo FAILED test $(@F:-result=). Aborting.; false)
 
+progs/%-time.csv: bin/time-%
+	$^ > $@
+
+%-bench: compare_times.py reference-times.csv progs/%-time.csv progs/%-speedup.txt
+	./$^
+
 clean:
-	rm -f out/* bin/* progs/*.txt
+	rm -f out/* bin/* progs/*-expected.txt progs/*-actual.txt progs/*-time.csv
 
-.PRECIOUS: out/%.o out/%.s bin/% progs/%-expected.txt progs/%-actual.txt
+.PRECIOUS: out/%.o out/%.s bin/% bin/time-% \
+	progs/%-expected.txt progs/%-actual.txt progs/%-time.csv

compare_times.py

+#!/usr/bin/env python3
+
+from collections import OrderedDict
+import csv
+import math
+import sys
+
+def read_times(filename):
+    times = OrderedDict()
+    with open(filename) as file:
+        for row in csv.DictReader(file):
+            times[row['test_name']] = {
+                'mean_log': float(row['mean_log_duration']),
+                'variance_log': float(row['variance_log_duration'])
+            }
+    return times
+
+if __name__ == '__main__':
+    (_, reference_file, new_file, speedup_file) = sys.argv
+    reference_times = read_times(reference_file)
+    new_times = read_times(new_file)
+    with open(speedup_file) as f:
+        expected_speedup = float(f.read().strip())
+
+    ((test_name, new_time),) = new_times.items()
+    time = reference_times[test_name]
+    mean_speedup = math.expm1(time['mean_log'] - new_time['mean_log'])
+    speedup_percent = abs(mean_speedup * 100)
+    speedup_direction = 'fast' if mean_speedup > 0 else 'slow'
+    variance_log_sum = time['variance_log'] + new_time['variance_log']
+    variance_percent = math.expm1(math.sqrt(variance_log_sum)) * 100
+    print(f'{test_name} ran {speedup_percent}% {speedup_direction}er than reference solution (+/- {variance_percent}%)')
+
+    print(f'Expected speedup: {expected_speedup * 100}% faster')
+    if mean_speedup < expected_speedup:
+        print('Make it faster!')
+        sys.exit(1)
+    else:
+        print("That's fast!")

progs/stage7-loops-of-ops-speedup.txt

+1.0

progs/stage7-unhash-speedup.txt

+0.25

reference-times.csv

+test_name,mean_log_duration,variance_log_duration
+stage1-1337,-15.414441,4.630224e-09
+stage1-42,-15.423754,3.730815e-09
+stage1-print-multiple,-14.880734,5.551399e-09
+stage2-1-plus-1,-15.417299,3.838244e-09
+stage2-1-plus-2-plus3,-15.399964,4.883277e-09
+stage2-1-plus-5,-15.418377,4.506159e-09
+stage2-5-plus-1,-15.416418,3.775031e-09
+stage2-big-stack,-15.048829,4.927516e-09
+stage2-overflow,-15.414238,4.393723e-09
+stage3-bad-order,-15.415961,4.549370e-09
+stage3-lots-of-ops,-12.756345,4.280501e-08
+stage3-overflow,-15.272850,4.365156e-09
+stage4-basic-division,-14.941708,5.003680e-09
+stage4-lots-of-ops,-11.212322,1.852049e-07
+stage5-big-locals,-15.223882,4.708205e-09
+stage5-local-test,-15.373016,3.674967e-09
+stage5-local-test2,-15.343883,4.535228e-09
+stage5-lots-of-ops,-10.598737,3.448534e-07
+stage6-comparisons,-15.313315,3.708140e-09
+stage7-bswap,-14.892616,5.035440e-09
+stage7-count-to-20,-15.085020,4.816644e-09
+stage7-count-together,-13.403312,2.162844e-08
+stage7-count-up-down,-14.693660,6.327085e-09
+stage7-digit-powers,-2.245703,2.760769e-04
+stage7-double-palindromes,-3.006717,1.672314e-04
+stage7-exponentiation,-10.989014,2.313973e-07
+stage7-fizz-buzz,-12.930649,4.318885e-08
+stage7-lcm,-8.051964,3.464892e-06
+stage7-loops-of-ops,-0.964310,1.200135e-04
+stage7-pascals-triangle,-11.415512,2.142535e-07
+stage7-pi-approx,-13.417496,2.351959e-08
+stage7-pi-exact,-0.860421,6.465658e-04
+stage7-primes,-6.798341,1.164016e-05
+stage7-riemann-sum,-5.495665,5.578510e-06
+stage7-sin,-8.071598,3.286681e-06
+stage7-sqrt,-13.943080,1.326310e-08
+stage7-square-digits,1.451112,8.851105e-06
+stage7-unhash,1.324347,1.066462e-08

call-check.s → runtime/call_check.s

+# This is a custom entry point that calls basic_main() for a compiled BASIC program
+# and verifies that it satisfies the x86-64 calling convention.
+# This means that the callee-save registers and all memory above %rsp
+# at the start of basic_main() must not be modified.
+
 .rodata
 check_failed_msg:
     .string "x86-64 calling convention violated\n"
 
 .text
-.globl check_start
-check_start:
+.globl _start
+_start:
     # Put 32 KB of canary data on the stack
     movq $-0x1000, %rcx
     leaq (%rsp, %rcx, 8), %rsp
@@ -22,8 +27,7 @@ check_start:
     movq $0xCB9FD8524A630E71, %r14
     movq $0xD0B5F947CEA23618, %r15
 
-    call main
-    movl %eax, %edx # save return value since we will overwrite it
+    call basic_main
 
     # Check that callee-save registers haven't changed
     movq $0xB42607DE9FA358C1, %rax
@@ -52,8 +56,8 @@ check_start:
     repe scasq
     jne check_failed
 
-    # Checks succeeded; exit with return value from main()
-    movl %edx, %edi
+    # Checks succeeded; exit with code 0
+    movl $0, %edi
     call exit@plt
 
     # Checks failed; print a warning message and exit with error status

runtime/print_int.c

+#include <inttypes.h>
+#include <stdio.h>
+#include "ast.h"
+
+// A function that can be called from assembly to print an integer
+void print_int(value_t value) {
+    printf("%" PRId64 "\n", value);
+    // Clobber all caller-save registers
+    asm(
+        "movq $0x6A2CFE91073BD845, %%rax\n"
+        "movq $0x03BAD7C14F2E6589, %%rdi\n"
+        "movq $0x5D41EA960C72F8B3, %%rsi\n"
+        "movq $0xEC364B2D5A7F9810, %%rdx\n"
+        "movq $0xFC85AD49320BE167, %%rcx\n"
+        "movq $0x529A48CDB7163E0F, %%r8\n"
+        "movq $0x92E1587A4BDCF630, %%r9\n"
+        "movq $0x47DC36501F89AEB2, %%r10\n"
+        "movq $0xAF4B29785C61ED30, %%r11\n"
+        : : : "rax", "rdi", "rsi", "rdx", "rcx", "r8", "r9", "r10", "r11"
+    );
+}

runtime/print_int_mock.c

+#include "ast.h"
+
+void print_int(value_t value) {
+    (void) value;
+}

runtime/timing.c

+#include <assert.h>
+#include <math.h>
+#include <stdint.h>
+#include <stdlib.h>
+#include <stdio.h>
+#include <string.h>
+#include <time.h>
+
+// The number of seconds in a nanosecond
+const double SEC_PER_NS = 1e-9;
+// The prefix of the executable name this will be compiled into
+const char TIME_EXECUTABLE_PREFIX[] = "bin/time-";
+
+// basic_main() is the assembly function produced by the compiler
+void basic_main(void);
+
+double time_main(void) {
+    // Compute the amount of CPU time used by basic_main()
+    struct timespec start, end;
+    clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &start);
+    basic_main();
+    clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &end);
+    // Compute the duration in seconds
+    return end.tv_sec - start.tv_sec + (end.tv_nsec - start.tv_nsec) * SEC_PER_NS;
+}
+
+int main(int argc, char *argv[]) {
+    assert(argc > 0);
+    assert(strncmp(argv[0], TIME_EXECUTABLE_PREFIX, strlen(TIME_EXECUTABLE_PREFIX)) == 0);
+    char *test_name = argv[0] + strlen(TIME_EXECUTABLE_PREFIX);
+
+    // Rerun basic_main() for at least a second and at least 3 times
+    double duration_sum = 0;
+    double duration_log_sum = 0, duration_log_square_sum = 0;
+    size_t runs = 0;
+    while (duration_sum < 1.0 || runs < 3) {
+        double duration = time_main();
+        duration_sum += duration;
+        double log_duration = log(duration);
+        duration_log_sum += log_duration;
+        duration_log_square_sum += log_duration * log_duration;
+        runs++;
+    }
+
+    /* Compute the mean and standard deviation of the estimated time basic_main() takes
+     * We use log(duration), so we compute the geometric mean and variance.
+     * This makes the mean much more resistant to large outliers. */
+    double mean_log_duration = duration_log_sum / runs;
+    double variance_log_duration =
+        (duration_log_square_sum / runs - mean_log_duration * mean_log_duration) / runs;
+    printf(
+        "test_name,mean_log_duration,variance_log_duration\n"
+        "%s,%f,%e\n",
+        test_name, mean_log_duration, variance_log_duration
+    );
+    fprintf(stderr, "%s mean duration: %e seconds (+/- %e x)\n",
+        test_name, exp(mean_log_duration), expm1(sqrt(variance_log_duration))
+    );
+}

src/compiler.c

 #include <stdlib.h>
 #include <stdio.h>
-#include <inttypes.h>
 
 #include "parser.h"
 #include "compile.h"
@@ -16,24 +15,11 @@ void usage(char *program) {
  * goes between the header and the footer.
  */
 void header(void) {
-    printf("%s",
-        "# Declares a string constant to pass to printf()\n"
-        ".section .rodata\n"
-        "intfmt:\n"
-        "    .string \"%" PRId64 "\\n\"\n"
-        "\n"
+    printf(
         "# The code section of the assembly file\n"
         ".text\n"
-        "print_int:\n"
-        "    # Calls printf(intfmt, %rdi)\n"
-        "    movq %rdi, %rsi\n"
-        "    leaq intfmt(%rip), %rdi # LABEL(%rip) computes the address of LABEL relative to %rip\n"
-        "    movb $0, %al # %al stores the number of float arguments to printf()\n"
-        "    call printf@plt\n"
-        "    ret\n"
-        "\n"
-        ".globl main\n"
-        "main:\n"
+        ".globl basic_main\n"
+        "basic_main:\n"
         "    # The main() function\n"
     );
 }
@@ -45,7 +31,6 @@ void header(void) {
  */
 void footer(void) {
     printf(
-        "    movl $0, %%eax # return 0 from main()\n"
         "    ret\n"
     );
 }