# 2020q1 Homework4 (khttpd) contributed by < `ZhuMon` > ###### tags: `linux2020`, `khttpd` ## Table of Contents [TOC] ## :fountain: 環境 ```shell $ cat /etc/lsb-release DISTRIB_ID=Ubuntu DISTRIB_RELEASE=18.04 DISTRIB_CODENAME=bionic DISTRIB_DESCRIPTION="Ubuntu 18.04.3 LTS" $ uname -a Linux yx 4.15.0-91-generic #92-Ubuntu SMP Fri Feb 28 11:09:48 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux $ gcc --version gcc (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0 $ lscpu Architecture: x86_64 CPU op-mode(s): 32-bit, 64-bit Byte Order: Little Endian CPU(s): 1 On-line CPU(s) list: 0 Thread(s) per core: 1 Core(s) per socket: 1 Socket(s): 1 NUMA node(s): 1 Vendor ID: GenuineIntel CPU family: 6 Model: 61 Model name: 06/3d Stepping: 4 CPU MHz: 1800.105 BogoMIPS: 3600.21 L1d cache: 32K L1i cache: 32K L2 cache: 4096K L3 cache: 16384K NUMA node0 CPU(s): 0 ``` ## 修改 khttpd ### Load fibdrv > 可讓用戶端藉由呼叫 `$wget localhost:1999/fib/10` 得到 $Fibonacci(10)$ 也就是 55 這個數字 * 將 fork 自 [bignum](https://github.com/sysprog21/bignum) 的 [bignum](https://github.com/ZhuMon/bignum) 作為 submodule 加入 khttpd * 在 bignum 中,參照 bn_print 實作 bn_return,回傳 10 進位的 fibonacci,並將 userspace 的 function 都改為 kernel 的 function * 在 http_server.c 中,呼叫 fibonacci ```cpp bn_t fib = BN_INITIALIZER; fibonacci(k, fib); content = bn_return(fib); ``` ---- ### Parse URL > 讓 server 知道 URL (`localhost:1999/fib/10`) 中,`/fib/10` 的意義 * 思路 * 一開始使用者不管輸入什麼 URL,都只會得到 `Hello World!` * 於是在 `http_server.c` 中,找出存有 `Hello World!` 字元的位置,發現位於兩個存放 http-message 的 macro * 了解運作原理後,更改 `http_server_response()` 中會回傳 `HTTP_RESPONSE_200_KEEP_ALIVE_DUMMY` 或 `HTTP_RESPONSE_200_DUMMY` 的部分,改為自己的 function,並且解析 URL * 作法 * 更改 `http_server_response()` ```cpp static int http_server_response(struct http_request *request, int keep_alive) { char *response; pr_info("requested_url = %s\n", request->request_url); if (request->method != HTTP_GET) response = keep_alive ? HTTP_RESPONSE_501_KEEPALIVE : HTTP_RESPONSE_501; else response = generate_response(request->request_url, keep_alive); http_server_send(request->socket, response, strlen(response)); return 0; } ``` * 新增 function `generate_response()` * 傳入 `url` 以便解析,傳入 `keep_alive` 保證兩種 connection 都可以得到相對應的輸出 * 使用 `strsep` 來分割 URL,確定傳入的 URL 開頭是 `fib`,且後面有接數字,才計算 fibonacci * 有想過另外將分割 URL 拉出來成另一個 function * 但是希望計算呼叫 `fibonacci` 依舊放在 `generate_response`,否則新 function 就不只有分割 URL 的功能,無法擴充 * 如此一來,勢必需要一個新的 data structure 來存放解析完的 URL,但是暫時不需要其他網址,所以專門寫一個新的 data structure 有點浪費,所以暫時將分割網址全寫在 `generate_response` * 使用 `snprintf` 產生 html response,方便擴充 * 使用 [你所不知道的 C 語言:數值系統篇](https://hackmd.io/@sysprog/c-numerics#Count-Leading-Zero) 所學到的計算 log10 的方法,計算數字的長度 > TODO: 確定不會 Overflow ```cpp static char *generate_response(char *url, int keep_alive) { // TODO: use macro in http_parser.c char *connection = keep_alive ? "Keep-Alive" : "Close"; // parse URL char *content = url; // assign to fibonacci iff url == "fib/[0-9]*" // first character is "/", ignore it ++url; char *path = strsep(&url, "/"); if (!strcmp(path, "fib") && (path = strsep(&url, "/"))) { long k = 1; bn_t fib = BN_INITIALIZER; if (kstrtol(path, 10, &k) == 0) { fibonacci(k, fib); content = bn_return(fib); } } // use log10 to count length of number size_t response_buf_size = strlen(HTTP_RESPONSE_200) + my_log10(strlen(content)) + 1 + strlen(connection) + strlen(content); char *response = kmalloc(response_buf_size, GFP_KERNEL); snprintf(response, response_buf_size, HTTP_RESPONSE_200, strlen(content), connection, content); return response; } ``` ### 加快 Cppcheck (已被修復) * 發現在 commit 時,需要很久時間(等了幾分鐘都沒辦法 commit),查看原因後,發現是卡在執行 Cppcheck > 在本機端 (macOS) commit 就沒有問題 > 不過 macOS 的 clang-format 會自動將本身的 header file 移至最前端,與 Ubuntu 的行為不同 * 試圖找出造成 Cppcheck 時間過長的問題 * 發現是在 check `http_parser.c` 時,時間過長 * 試著不要 check `http_parser.c` * 使用 txt 檔紀錄其他檔案 * 在使用 `-I` 時,不要從現行目錄找尋,因為目前只有 `compat` 這個 Library 目錄,於是直接給予相對路徑 * `scripts/pre-commit.hook` ```shell CPPCHECK_suppresses="--suppress=missingIncludeSystem" CPPCHECK_OPTS="-I ./compat --enable=all --error-exitcode=1 --force $CPPCHECK_suppresses --file-list=file_to_check.txt" ``` * `file_to_check.txt` ```txt main.c htstress.c http_parser.h http_server.c http_server.h ``` * 後來發現可以使用 `-i http_parser.c` 直接排除不要檢查的檔案 > 一直以為是電腦的問題,還一直重開機,或是刪除 sshfs,也有想要重新安裝 Ubuntu,甚至想要重新買一台電腦 Orz > 好險後來交叉比對後,發現確實只有 khttpd 的 commit 速度過慢,抽絲剝繭後才找到原因... > 而且有人竟然在兩天前就找到這個問題了... --- ### 將每次連線視為 not keep alive * 參考 [server framework](https://hackmd.io/@ktvexe/B1s8hX1yg) * 向 khttpd 發送 request 後,會顯示接收錯誤 ``` [ 846.397997] khttpd: recv error: -104 ``` * 發現 wget 每次的 request 都會要求是 keep_alive,造成負責該次連線的 server thread 接收一次的請求後,還繼續等待,可是 wget 卻已經先結束了 * 解決方法:將每次的 request 視為 not keep alive * 在 `http_server_worker()` 中,只要處理完 request 就結束,不考慮 keep alive ```diff while (!kthread_should_stop()) { int ret = http_server_recv(socket, buf, RECV_BUFFER_SIZE - 1); if (ret <= 0) { if (ret) pr_err("recv error: %d\n", ret); break; } http_parser_execute(&parser, &setting, buf, ret); - if (request.complete && !http_should_keep_alive(&parser)) + if (request.complete) break; } ``` * 重新測試時間 ```shell $ make check ``` * 結果 ``` requests: 100000 good requests: 100000 [100%] bad requests: 0 [0%] socker errors: 0 [0%] seconds: 13.478 requests/sec: 7419.394 ``` ~~發現比原本(923.196 requests/sec) 多了 7 倍~~ (重新測試後,發現原本的速度也提升到 8000 request/sec 附近) :::warning TODO: 對照 [高效能 Web 伺服器開發](https://hackmd.io/@sysprog/fast-web-server) 對於關閉連線的處理機制,解釋上述實驗結果。 :notes: jserv ::: :::info 可是重新測試未更改前的 code,發現每秒處理的 request 數量跟修改過的差不多 反覆測試幾次後,發現是否取消 keep-alive 對效能影響並不顯著, ![](https://i.imgur.com/Zj8iUxW.png) 前幾次是在有開 Chrome 的狀態下跑的,數據較差,後幾次在重開機後跑的,明顯看到處理速度大幅提升 ::: * ``` requests: 100000 good requests: 100000 [100%] bad requests: 0 [0%] socker errors: 0 [0%] seconds: 18.403 requests/sec: 5433.807 Complete ``` 重新測試,發現速度又降下來了 * ``` requests: 100000 good requests: 100000 [100%] bad requests: 0 [0%] socker errors: 0 [0%] seconds: 9.608 requests/sec: 10407.755 ``` 反覆測試,發現處理 request 的速度並不穩定,可能跟當前運行的程式有關,以上是我重新開機後,不執行瀏覽器等耗費資源的程式,所產生的數據 ## :memo: 初始測試 > 標題為測資,分別為 「request 總數」、「使用的 socket 數量」、「使用的 threads 數量」、「傳送 request 的目標網站」 ### 100000 requests, 1 socket, 4 threads, localhost * 命令 ```shell $ make check ``` * 結果 ``` 10000 requests 20000 requests 30000 requests 40000 requests 50000 requests 60000 requests 70000 requests 80000 requests 90000 requests requests: 100000 good requests: 100000 [100%] bad requests: 0 [0%] socker errors: 0 [0%] seconds: 12.295 requests/sec: 8133.262 ``` ~~每秒竟然只能處理不到 1000 個 request~~ ~~不知道為什麼處理速度提升到了 8000 個 request~~ 將其他耗費大量網路資源的程式(e.g. Chrome)關閉,測得的數字 --- ### 1000 requests, 1 socket, 4 threads, `http://www.google.com` * 命令 ```shell $ ./htstress -n 1000 -c 1 -t 4 http://www.google.com/ ``` * 結果 ``` requests: 1000 good requests: 1000 [100%] bad requests: 0 [0%] socker errors: 0 [0%] seconds: 97.798 requests/sec: 10.225 ``` 發現處理速度更慢了 --- > 思考若是使用更多的 thread 或更多的 socket,是否可以加速處理速度 首先實驗多 Thread ### 1000 requests, 1 socket, 16 threads, `http://www.google.com` * 命令 ```shell $ ./htstress -n 1000 -c 1 -t 16 http://www.google.com/ ``` * 結果 ```shell 0 requests 100 requests 200 requests EPOLLERR caused by unknown error 300 requests 400 requests EPOLLERR caused by unknown error 500 requests 600 requests EPOLLERR caused by unknown error 700 requests 800 requests 900 requests EPOLLERR caused by unknown error requests: 1000 good requests: 1000 [100%] bad requests: 0 [0%] socker errors: 444 [44%] seconds: 46.680 requests/sec: 21.422 ``` 發現處理速度確實有提升(10.225 -> 21.422),但是 socker errors 也提升到了 44 %,也多了很多 `EPOLLERR caused by unknown error` 看過 htstress source code 後,知道 `-t` 要對應到本身的核心數量,也許便是這個原因 > TODO: 查出真正原因 --- ## 與 www.protocol5.com/Fibonacci 比較 ### 限制 * 先測試 $Fibonacci($ 2 ^31^ $-1)$ 可不可以找到結果,發現無法 http://www.protocol5.com/Fibonacci/2147483647.htm * 反覆測試後,發現最大極限為 $Fibonacci(3872001)$ http://www.protocol5.com/Fibonacci/3872001.htm http://www.protocol5.com/Fibonacci/3872002.htm ![](https://i.imgur.com/ENJcen6.png) ### 使用 [python 程式](https://github.com/ZhuMon/khttpd/blob/master/get_fib.py) 驗證運算結果 * 在該程式內比較兩者並且記錄兩者請求所需時間 * 使用 `requests` 獲得網頁資訊 * 使用 regular expression: `re` 來解析 html * 使用 `time.time()` 來記錄時間 * TODO: 更新檔案 ```python import requests import re import argparse import time def pt5_fib(num): url = f"http://www.protocol5.com/Fibonacci/{num}.htm" prev = time.time() content = requests.get(url) tick = time.time() - prev pattern = "<li><h4>Decimal Base 10:</h4><div>[0-9]*</div>" match_text = re.findall(pattern, content.text) res = match_text[0].split("<div>")[1].split("</div>")[0] return res, tick def khttpd_fib(num): url = f"http://localhost:{args.port}/fib/{num}" prev = time.time() res = requests.get(url) tick = time.time() - prev return res.text, tick def main(args): if args.num: print("match" if pt5_fib(args.num)[0] == khttpd_fib(args.num)[0] else "not equal") else: output = open("pt5_khttpd.txt", "w") for i in range(1, 100): pf, pt = pt5_fib(i) kf, kt = khttpd_fib(i) if pf != kf: print(f"not equal at fib({i})") break output.write(f"{i}\t{pt:.4f}\t{kt:.4f}\n") if i % 10 == 0: print(f"{i}/100") if __name__ == "__main__": parser = argparse.ArgumentParser() parser.add_argument("-p", "--port", help="The port khttpd use", dest="port", default=1999) parser.add_argument("-n", "--num", help="The number for fibonacci", dest="num", default=0) args = parser.parse_args() main(args) ``` ### 時間測試 ![](https://i.imgur.com/WhU7bnk.png) 在小範圍(0~100)內,protocol5的所需時間明顯遠高於 khtppd ![](https://i.imgur.com/TSfmjsL.png) 在 100 萬以內,可以看到 protocol5 的速度趨於平緩,雖然有些時候會很高,但是總體來說,時間不會上升太多;而 khttpd 則是明顯逐漸上升,甚至有些時候會超出 protocol5 所需時間 ![](https://i.imgur.com/wvstV43.png) 在全部範圍(protocol5 只到 3872001)內,protocol5 的跳動更大,而 khttpd 在大於 200 萬後,更是幾乎超過 protocol5 * protocol5 的變動應該是因為網路的速度不穩定,所以會有劇烈變化 * TODO: 找出 khttpd 有時候會變快的原因 * 猜測是有時候電腦的一些 task 結束,所以 CPU 可以花更多資源在處理 fibonacci ## 計算 http 請求到 khttpd 回應的時間 ### 方法 1. 使用 `wget` 得到 http header > 由於使用 Ubuntu server 進行開發,故無圖形介面 2. 使用 linux 的命令 `time` 得到 `wget` 的完整時間 > TODO:改成其他命令 > $\because$ 在 `bash` 環境中,`time` 的精準度只有到毫秒 (ms) * ### 結果 ![](https://i.imgur.com/Gi4eshY.png) > 暫時只用到 300 萬 > 目前結果只使用 [ZhuMon/bignum](https://github.com/ZhuMon/bignum) 來計算 fibonacci > 待改進 ## :warning: 錯誤 1. 向 khttpd 連續發送 40 個 request 後,被鎖起來了 ``` [ 9572.867014] watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [khttpd:15928] [ 9572.867545] Modules linked in: khttpd(OE) ppdev intel_rapl_perf input_leds joydev serio_raw parport_pc parport qemu_fw_cfg mac_hid binfmt_misc sch_fq_codel ib_iser rdma_cm iw_cm ib_cm ib_core iscsi_tcp libiscsi_tcp libiscsi nfsd auth_rpcgss nfs_acl lockd grace scsi_transport_iscsi sunrpc ip_tables x_tables autofs4 btrfs zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear hid_generic usbhid hid crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd glue_helper cryptd virtio_gpu ttm drm_kms_helper syscopyarea sysfillrect sysimgblt psmouse virtio_blk e1000 fb_sys_fops drm i2c_piix4 pata_acpi [last unloaded: khttpd] [ 9572.867588] CPU: 0 PID: 15928 Comm: khttpd Tainted: G OE 4.15.0-91-generic #92-Ubuntu [ 9572.867589] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014 [ 9572.867597] RIP: 0010:apm_get_str+0x526/0x620 [khttpd] [ 9572.867599] RSP: 0018:ffffa428c1677bf0 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff11 [ 9572.867600] RAX: bc002e0e22586d09 RBX: 0000000000000013 RCX: 8ac7230489e80000 [ 9572.867601] RDX: 062125fd081445e3 RSI: ffff939f10847f40 RDI: ffff939f10840000 [ 9572.867602] RBP: ffffa428c1677c40 R08: 0000000000026d00 R09: 000000000008e6d6 [ 9572.867603] R10: ffff939f0f0631ae R11: 0000000000000000 R12: 000000000000000a [ 9572.867604] R13: 0000000000002cd0 R14: ffff939f0f0631af R15: 0000000000002cd1 [ 9572.867607] FS: 0000000000000000(0000) GS:ffff939f3fc00000(0000) knlGS:0000000000000000 [ 9572.867608] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 9572.867609] CR2: 00007f48f4ab6120 CR3: 00000000be00a005 CR4: 00000000003606f0 [ 9572.867610] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 9572.867611] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 9572.867612] Call Trace: [ 9572.867619] apm_return+0xa2/0x110 [khttpd] [ 9572.867622] bn_return+0x20/0x30 [khttpd] [ 9572.867625] http_parser_callback_message_complete+0x271/0x2c0 [khttpd] [ 9572.867631] ? vprintk_func+0x46/0xc0 [ 9572.867634] ? sock_recvmsg+0x43/0x50 [ 9572.867637] http_parser_execute+0x3796/0x39b0 [khttpd] [ 9572.867640] ? http_parser_execute+0x3796/0x39b0 [khttpd] [ 9572.867643] http_server_worker+0x130/0x1c0 [khttpd] [ 9572.867646] ? http_parser_callback_request_url+0x20/0x20 [khttpd] [ 9572.867649] ? http_parser_callback_message_complete+0x2c0/0x2c0 [khttpd] [ 9572.867651] ? kmalloc+0x10/0x10 [khttpd] [ 9572.867654] ? http_parser_callback_message_begin+0x40/0x40 [khttpd] [ 9572.867656] ? http_parser_callback_header_field+0x10/0x10 [khttpd] [ 9572.867659] ? http_server_worker+0x1c0/0x1c0 [khttpd] [ 9572.867661] ? http_server_send+0xe0/0xe0 [khttpd] [ 9572.867665] kthread+0x121/0x140 [ 9572.867667] ? http_server_recv.constprop.1+0x90/0x90 [khttpd] [ 9572.867668] ? kthread+0x121/0x140 [ 9572.867671] ? http_server_recv.constprop.1+0x90/0x90 [khttpd] [ 9572.867673] ? kthread_create_worker_on_cpu+0x70/0x70 [ 9572.867677] ret_from_fork+0x35/0x40 [ 9572.867678] Code: 34 f0 48 8d 3c d6 48 89 ca 48 8b 4d c8 eb 0d 31 d2 48 f7 f1 48 39 f7 48 89 06 74 17 48 83 ee 08 48 85 d2 48 8b 06 74 e7 48 f7 f1 <48> 39 f7 48 89 06 75 e9 48 89 d0 48 89 d1 31 d2 49 f7 f4 0f b6 ``` * 查找資料後,發現是 CPU 負載過重,想到 [AndybnACT](https://hackmd.io/@AndybnA/khttpd) 同學有說到 kthread 沒有被釋放,決定試試他的方法 > TODO: > 釋放 kthread * ~~發現由於我是使用 wget 進行連線,所以每次請求完,thread 便會關閉(顯示 `recv error: -104`),所以不是 kthread 問題,應該是未安插 `preempt_enable(), preempt_disable()` 導致 CPU 被佔住~~ :::warning 客戶端連線可能會提早關閉,這點需要由 kHTTPd 來處理 :notes: jserv ::: 2. 開機後 insmod ,並使用 wget 請求網頁時,會發生 ```shell [ 6965.449237] khttpd: loading out-of-tree module taints kernel. [ 6965.449297] khttpd: module verification failed: signature and/or required key missing - tainting kernel [ 6965.477421] khttpd: requested_url = /fib/10 ``` --- > TODO: > - [ ] 試試在 host 能不能打開網頁