# 2020q2 Homework2 (fibdrv)
contributed by < `MetalheadKen` >

> [H03: fibdrv](https://hackmd.io/@sysprog/linux2020-fibdrv)

## 實驗環境

$ uname -a
Linux kendai-XPS-13-9360 4.15.0-43-generic #46-Ubuntu SMP Thu Dec 6 14:45:28 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

$ gcc --version | head -n 1
gcc (Ubuntu 7.3.0-27ubuntu1~18.04) 7.3.0

## 效能分析
### 排除干擾效能分析的因素
* 限定 CPU 給特定的程式使用
* 修改 `/boot/grub/grub.cfg` 的 boot 的參數，將開機命令 `linux` 後面加上 `isolcpus=7` 來讓第 7 個 CPU 在開機時就可以被保留下來。
* 抑制 ASLR

$ sudo sh -c "echo 0 > /proc/sys/kernel/randomize_va_space"

* 設定 `scaling_governor` 為 performance

$ sudo sh -c "echo performance > /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor"

* 針對 intel 處理器，關閉 turbo mode

$ sudo sh -c "echo 1 > /sys/devices/system/cpu/intel_pstate/no_turbo"

### 使用 ftrace 來進行效能分析
為了進行效能量測，通常都會盡量避免修改原始碼並重新編譯。有鑑於此，這邊採取使用 [ftrace](https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt) 來進行效能分析，藉由透過 kprobe 和 kretprobe 來計算 kernel space 執行時間，以及透過 uprobe 和 uretprobe 來計算 user space 的執行時間。

### 計算核心執行時間
為了要計算 kernel space 的執行時間，在這邊利用 [kprobes](https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt) 的技術來安插 probe 到想要量測的 function 中。

舉例來說，若要安插 probe 到 `fibdrv.c` 的 `fib_read` 的開頭的話可以這樣寫

$ sudo sh -c "echo 'p:kstart fibdrv:fib_read' >> /sys/kernel/debug/tracing/kprobe_events"

而若要安插 probe 到 `fibdrv.c` 的 `fib_read` 的回傳結尾的話可以這樣寫

$ sudo sh -c "echo 'r:kend fibdrv:fib_read' >> /sys/kernel/debug/tracing/kprobe_events"

最後若要移除上面兩個 probe 的時候可以這樣寫

$ sudo sh -c "echo '-:kstart' >> /sys/kernel/debug/tracing/kprobe_events"
$ sudo sh -c "echo '-:kend' >> /sys/kernel/debug/tracing/kprobe_events"

當透過 ftrace 追蹤時，當觸發 probe 的時候就會印出執行 probe 安插的地方的 CPU id、timestamp、irq 和 schedule 等相關資訊，如此一來就可以很輕鬆地進行程式分析。

### 計算使用者執行時間
與上面不同的是，為了要計算 user space 的執行時間，在這邊是使用 [uprobes](https://www.kernel.org/doc/Documentation/trace/uprobetracer.txt) 而不是 [kprobes](https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt)

比較麻煩的是，與 kprobes 不同，uprobes 在 ftrace 並沒有像 [perf-tools](https://github.com/brendangregg/perf-tools) 中使用 uprobes 的方法一樣有一個比較直覺的方式撰寫，相反的如 [kernel doc](https://www.kernel.org/doc/Documentation/trace/uprobetracer.txt) 所說，當我們要安插 probe 到 user space 的時候，要給予要插入的 offset 位置而不是要插入的 function name。

舉例來說，若要安插 probe 到 `client.c` 的 `read` 的時候我們需要透過 `objdump` 工具來搜尋 `read` 函式的 offset

$ objdump -d ./client | grep -w read

0000000000000840 <read@plt>:
 840:   ff 25 5a 17 20 00       jmpq   *0x20175a(%rip)        # 201fa0 <read@GLIBC_2.2.5>
 b12:   e8 29 fd ff ff          callq  840 <read@plt>
 b72:   e8 c9 fc ff ff          callq  840 <read@plt>

由上面可知 `read` 的 offset 為 `0x840`，因此我們可以這樣寫來安插 uprobe

$ sudo sh -c "echo 'p:ustart /path/to/client:0x840' >> /sys/kernel/debug/tracing/uprobe_events"
$ sudo sh -c "echo 'r:uend /path/to/client:0x840' >> /sys/kernel/debug/tracing/uprobe_events"

### 後續處理
最後比較麻煩的是，ftrace 最後會將結果全部輸出到 `/sys/kernel/debug/tracing/trace` 裡，因為沒辦法像 bpftrace 一樣可以在 runtime 的時候計算執行時間差，因此我們需要透過讀取檔案並提取我們要的資訊來計算執行的時間差。程式碼總結如下：

:::danger
既然寫成 shell script，應避免 hardcoded path，例如下方的 `USER_DIR`，可善用 [dirname](https://linux.die.net/man/3/dirname) 一類的命令。
:notes: jserv
:::

* `client_perf.sh`

#!/bin/bash

###
# Store original value about system performance
###
ORIG_ASLR=$(cat /proc/sys/kernel/randomize_va_space)
ORIG_SCAL=$(cat /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor)
ORIG_NTURBO=$(cat /sys/devices/system/cpu/intel_pstate/no_turbo)

###
# Reduce factor of interference performance benchmark
###
echo 0 > /proc/sys/kernel/randomize_va_space
echo performance > /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor
echo 1 > /sys/devices/system/cpu/intel_pstate/no_turbo

####
# Get offset of user-space read function
####
USER_DIR=/home/kendai/git/fibdrv
READ_OFFSET=0x$(objdump -d ${USER_DIR}/client | grep 'read.*:' | sed -e 's/^0*//' -e 's/ .*//')

####
# Use ftrace to record function timestamp
####
COMMAND="$@"
DEBUG_FS=/sys/kernel/debug
CURRENT_TRACER="function"

# Enable
cat /dev/null > $DEBUG_FS/tracing/trace
echo "$CURRENT_TRACER" > $DEBUG_FS/tracing/current_tracer
echo "mono" > $DEBUG_FS/tracing/trace_clock
echo "p:user_start_time ${USER_DIR}/client:${READ_OFFSET}" >> $DEBUG_FS/tracing/uprobe_events
echo "r:user_end_time ${USER_DIR}/client:${READ_OFFSET}" >> $DEBUG_FS/tracing/uprobe_events
echo 'p:kernel_start_time fibdrv:fib_read' >> $DEBUG_FS/tracing/kprobe_events
echo 'r:kernel_end_time fibdrv:fib_read' >> $DEBUG_FS/tracing/kprobe_events
echo 'r:lseek_probe fibdrv:fib_device_lseek ret=$retval' >> $DEBUG_FS/tracing/kprobe_events
echo 1 > $DEBUG_FS/tracing/events/uprobes/enable
echo 1 > $DEBUG_FS/tracing/events/kprobes/enable
echo 1 > $DEBUG_FS/tracing/tracing_on

# Run
eval "$COMMAND"
# Stop
echo 0 > $DEBUG_FS/tracing/tracing_on
# Extract needed information
# cp $DEBUG_FS/tracing/trace $USER_DIR/trace.tmp
grep -e 'user_start_time' -e 'user_end_time' $DEBUG_FS/tracing/trace > $USER_DIR/user_time.tmp
grep -e 'kernel_start_time' -e 'kernel_end_time' $DEBUG_FS/tracing/trace > $USER_DIR/kernel_time.tmp
grep -e 'lseek_probe' $DEBUG_FS/tracing/trace > $USER_DIR/lseek_offset.tmp

# Disable
echo 0 > $DEBUG_FS/tracing/events/kprobes/enable
echo 0 > $DEBUG_FS/tracing/events/uprobes/enable
echo "local" > $DEBUG_FS/tracing/trace_clock
echo '-:lseek_probe' >> $DEBUG_FS/tracing/kprobe_events
echo '-:kernel_end_time' >> $DEBUG_FS/tracing/kprobe_events
echo '-:kernel_start_time' >> $DEBUG_FS/tracing/kprobe_events
echo '-:user_end_time' >> $DEBUG_FS/tracing/uprobe_events
echo '-:user_start_time' >> $DEBUG_FS/tracing/uprobe_events
echo 'nop' > $DEBUG_FS/tracing/current_tracer
cat /dev/null > $DEBUG_FS/tracing/trace

####
# Calculate user & kernel function duration
####
rm -f $USER_DIR/client_time

cnt=1
while [ $cnt -le 100 ] && IFS=" " read -r -u 4 user1 && IFS=" " read -r -u 5 kernel1 && IFS=" " read -r -u 6 lseek; do
    ((cnt++))
    read -r -u 4 user2
    read -r -u 5 kernel2

    ustart=$(echo $user1 | cut -d " " -f 4 | sed 's/.$//')
    uend=$(echo $user2 | cut -d " " -f 4 | sed 's/.$//')
    kstart=$(echo $kernel1 | cut -d " " -f 4 | sed 's/.$//')
    kend=$(echo $kernel2 | cut -d " " -f 4 | sed 's/.$//')
    offset=$(echo $lseek | cut -d " " -f 9 | sed 's/^[a-z0-9]*=//')

    utime=$(echo "scale=6; ($uend-$ustart)*1000000" | bc | sed 's/.[0]*$//')
    ktime=$(echo "scale=6; ($kend-$kstart)*1000000" | bc | sed 's/.[0]*$//')

    echo "$(($offset)) $utime $ktime" >> $USER_DIR/client_time
done 4<$USER_DIR/user_time.tmp 5<$USER_DIR/kernel_time.tmp 6<$USER_DIR/lseek_offset.tmp

rm *.tmp

###
# Restore value about system performance
###
echo "$ORIG_ASLR" > /proc/sys/kernel/randomize_va_space
echo "$ORIG_SCAL" > /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor
echo "$ORIG_NTURBO" > /sys/devices/system/cpu/intel_pstate/no_turbo

* `Makefile`

--- a/Makefile
+++ b/Makefile
@@ -18,7 +18,7 @@ $(GIT_HOOKS):
 
 clean:
        $(MAKE) -C $(KDIR) M=$(PWD) clean
-       $(RM) client out
+       $(RM) client out client_time client_time.png
 load:
        sudo insmod $(TARGET_MODULE).ko
 unload:
@@ -39,3 +39,11 @@ check: all
        $(MAKE) unload
        @diff -u out scripts/expected.txt && $(call pass)
        @scripts/verify.py
+
+plot: all
+       $(MAKE) unload
+       $(MAKE) load
+       @sudo ./client_perf.sh taskset -c 7 ./client > out
+       $(MAKE) unload
+       @gnuplot client_time.gp
+       @eog client_time.png

之後執行 `make plot` 即可繪製結果成圖表

###### tags: `linux2020`