redisgate Gent helio helio_ping_iouring_server

Helio ping_iouring_server

---

소개

이 서버는 레디스 명령을 받아 분석(parsing)합니다.
'PING'을 받으면 'PONG'을 리턴하고, 기타 명령은 'OK'를 리턴합니다.
(실제 레디스 명령을 실행하는 것은 아닙니다.)
여러 개 스레드를 사용할 수 있고, io_uring, fiber를 사용합니다.

목차

• 성능 테스트
• 실행 옵션
• 서버 로그
• 소스 설명

성능 테스트

📦 성능 테스트 환경

ping_iouring_server를 스레드 1개, 2개, 5개, 10개로 테스트했습니다.
성능 테스트 툴은 redis-benchmark를 사용합니다. benchmark를 1개 실행하기도 하고, 2개, 3개, 4개, 5개를 동시에 실행해서 테스트했습니다.

• 테스트 장비(H/W): LG노트북 gram Intel i5-1335U(13th) 2.50GHz
  코어:10, 논리 프로세서:12, L1 캐시: 928KB, L2: 6.5MB, L3: 12.0MB
• 호스트 OS: Windows 11, VM: CentOS 9 (10코어 설정)
• 컴파일 build-dbg$ ninja -j1 ping_iouring_server
• 서버 실행: build-dbg$ ping_iouring_server --proactor_threads=1
  스레드 개수를 1, 2, 5, 10로 테스트했다.
• 테스트 툴 실행: redis-benchmark를 하나 또는 여러 개 동시 실행해서 테스트했습니다.
  $ bin/redis-benchmark -p 6380 -t set -d 10 -n 1000000 -q
• 측정 단위: 초당 명령 실행 수 rps(requests per second).
• p50 설명: 50%를 처리하는데 1개당 처리 시간입니다. p50=1.695msec이면 100만개의 요청 중에 50만개를 처리하는데 1개당 1.694msec 이내로 처리했다는 것입니다.

📦 요약

Server Thread=10, benchmark 10개(동시 실행) 일 때가 93361 rps로 가장 높게 나왔습니다.
p50 기준으로 보면 Thread=5, benchmark 5개가 1.423 msec로 가장 빠르게 나왔습니다.

• Server Thread=1,   benchmark   2개: 30406 rps, p50=2.679 msec, CPU Server:   66%, benchmark:   77%
• Server Thread=2,   benchmark   3개: 77349 rps, p50=1.695 msec, CPU Server: 134%, benchmark: 156%
• Server Thread=5,   benchmark   5개: 86145 rps, p50=1.423 msec, CPU Server: 296%, benchmark: 226%
• Server Thread=10, benchmark 10개: 93361 rps, p50=2.655 msec, CPU Server: 314%, benchmark: 269%

📦 Thread=1 테스트

• 서버 실행: build-dbg$ ping_iouring_server --proactor_threads=1
• 테스트 툴 실행: $ bin/redis-benchmark -p 6380 -t set -d 10 -n 1000000 -q
• 요약: benchmark 2개 일 때 30406 rps로 가장 높게 나왔다.
  • benchmark 1개 -> 29172 rps, CPU Server: 70%, benchmark: 64%, p50=1.311 msec
  • benchmark 2개 -> 30406 rps, CPU Server: 66%, benchmark: 77%, p50=2.679 msec
  • benchmark 3개 -> 24376 rps, CPU Server: 65%, benchmark: 74%, p50=4.975 msec
• benchmark 1개, 4회 실행 -> 29172 rps, CPU Server: 70%, benchmark: 64%
  • 1회 SET: 28772 requests per second, p50=1.311 msec
  • 2회 SET: 30375 requests per second, p50=1.231 msec
  • 3회 SET: 29940 requests per second, p50=1.263 msec
  • 4회 SET: 27601 requests per second, p50=1.335 msec
  • CPU 사용량 %Cpu0 : 9.8 us, 52.4 sy, 0.0 ni, 0.0 id, 2.4 wa, 6.1 hi, 29.3 si, 0.0 st %Cpu1 : 2.1 us, 13.8 sy, 0.0 ni, 73.4 id, 0.0 wa, 2.1 hi, 8.5 si, 0.0 st %Cpu4 : 4.5 us, 22.5 sy, 0.0 ni, 53.9 id, 0.0 wa, 4.5 hi, 14.6 si, 0.0 st PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2629 redis 20 0 82092 8596 7040 S 70.6 0.1 0:54.96 ping_iouring_server 2651 redis 20 0 18500 9932 3456 R 64.7 0.1 0:06.05 redis-benchmark
• benchmark 2개, 1회 실행 -> 30406 rps, CPU Server: 66%, benchmark: 77%
  • SET: 15204.73 requests per second, p50=2.679 msec
  • SET: 15202.65 requests per second, p50=2.679 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2288 redis 20 0 82092 10880 6912 S 66.7 0.1 0:53.32 ping_iouring_server 2425 redis 20 0 18500 10056 3584 R 40.0 0.1 0:16.33 redis-benchmark 2426 redis 20 0 18500 10184 3584 S 37.1 0.1 0:15.39 redis-benchmark
• benchmark 3개, 1회 실행 -> 24376 rps, CPU Server: 65%, benchmark: 74%
  • SET: 8184.65 requests per second, p50=4.975 msec
  • SET: 8080.87 requests per second, p50=4.983 msec
  • SET: 8112.01 requests per second, p50=4.975 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2288 redis 20 0 82092 11608 6912 S 64.8 0.1 1:19.37 ping_iouring_server 2463 redis 20 0 18500 10180 3584 R 25.7 0.1 0:02.63 redis-benchmark 2462 redis 20 0 18500 10056 3584 S 24.8 0.1 0:02.96 redis-benchmark 2461 redis 20 0 18500 9928 3456 R 23.8 0.1 0:03.49 redis-benchmark

📦 Thread=2 테스트

• 서버 실행: build-dbg$ ping_iouring_server --proactor_threads=2
  benchmark 실행 전 wa가 100이다. %Cpu0 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id, 99.1 wa, 0.0 hi, 0.9 si, 0.0 st %Cpu1 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id,100.0 wa, 0.0 hi, 0.0 si, 0.0 st PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2656 redis 20 0 147952 7808 6912 S 0.0 0.1 0:00.08 ping_iouring_server
• 테스트 툴 실행: $ bin/redis-benchmark -p 6380 -t set -d 10 -n 1000000 -q
• 요약: benchmark 3개 일 때 77349 rps로 가장 높게 나왔다.
  • benchmark 1개 -> 21348 rps, CPU Server: 105%, benchmark: 61%, p50=1.239 msec
  • benchmark 2개 -> 46029 rps, CPU Server: 143%, benchmark: 131%, p50=1.527 msec
  • benchmark 3개 -> 77349 rps, CPU Server: 134%, benchmark: 156%, p50=1.695 msec
  • benchmark 4개 -> 69346 rps, CPU Server: 126%, benchmark: 149%, p50=2.495 msec
• benchmark 1개, 2회 실행 -> 21348 rps, CPU Server: 105%, benchmark: 61%
  • 1회 SET: 21967.88 requests per second, p50=1.239 msec
  • 2회 SET: 20729.25 requests per second, p50=1.271 msec
  • CPU 사용량 %Cpu0 : 8.6 us, 48.4 sy, 0.0 ni, 0.0 id, 23.7 wa, 4.3 hi, 15.1 si, 0.0 st %Cpu1 : 9.2 us, 48.0 sy, 0.0 ni, 0.0 id, 22.4 wa, 7.1 hi, 13.3 si, 0.0 st %Cpu3 : 3.0 us, 22.2 sy, 0.0 ni, 58.6 id, 0.0 wa, 2.0 hi, 14.1 si, 0.0 st PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2656 redis 20 0 147952 8576 6912 S 104.9 0.1 0:07.67 ping_iouring_server 2662 redis 20 0 18500 9928 3456 R 60.8 0.1 0:04.51 redis-benchmark
• benchmark 2개(동시 실행) -> 46029 rps, CPU Server: 143%, benchmark: 131%
  • SET: 22928.94 requests per second, p50=1.527 msec
  • SET: 23101.62 requests per second, p50=1.527 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2507 redis 20 0 147952 8960 6912 S 143.6 0.1 0:11.30 ping_iouring_server 2511 redis 20 0 18500 10060 3584 R 66.3 0.1 0:05.21 redis-benchmark 2512 redis 20 0 18500 10188 3584 R 65.3 0.1 0:04.67 redis-benchmark
• benchmark 3개(동시 실행) -> 77349 rps, CPU Server: 134%, benchmark: 156%
  • SET: 25661.42 requests per second, p50=1.695 msec
  • SET: 25817.78 requests per second, p50=1.695 msec
  • SET: 25871.21 requests per second, p50=1.687 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2507 redis 20 0 147952 9820 6912 S 134.0 0.1 1:12.81 ping_iouring_server 2553 redis 20 0 18500 10188 3584 R 52.4 0.1 0:05.12 redis-benchmark 2554 redis 20 0 18500 10060 3584 R 52.4 0.1 0:04.57 redis-benchmark 2555 redis 20 0 18500 9928 3456 R 51.5 0.1 0:04.03 redis-benchmark
• benchmark 4개(동시 실행) -> 69346 rps, CPU Server: 126%, benchmark: 149%
  • SET: 17421.91 requests per second, p50=2.495 msec
  • SET: 17278.92 requests per second, p50=2.495 msec
  • SET: 17289.97 requests per second, p50=2.503 msec
  • SET: 17358.10 requests per second, p50=2.495 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2507 redis 20 0 147952 13560 6912 S 126.5 0.2 2:07.09 ping_iouring_server 2647 redis 20 0 18500 9928 3456 R 39.2 0.1 0:03.27 redis-benchmark 2646 redis 20 0 18500 9928 3456 R 37.3 0.1 0:03.96 redis-benchmark 2648 redis 20 0 18500 10056 3584 R 37.3 0.1 0:02.84 redis-benchmark 2645 redis 20 0 18500 9928 3456 R 35.3 0.1 0:04.46 redis-benchmark

📦 Thread=5 테스트

• 서버 실행: build-dbg$ ping_iouring_server --proactor_threads=5
  benchmark 실행 전 Cpu0~4번까지 100 wa이다. %Cpu0 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id,100.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu1 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id,100.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu2 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id,100.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu3 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id,100.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu4 : 0.0 us, 0.0 sy, 0.0 ni, 0.0 id,100.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu5 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu6 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu7 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu8 : 0.0 us, 1.0 sy, 0.0 ni, 99.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu9 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
• 테스트 툴 실행: $ bin/redis-benchmark -p 6380 -t set -d 10 -n 1000000 -q
• 요약: benchmark 5개 일 때 86145 rps로 가장 높게 나왔다.
  • benchmark   1개 -> 22830 rps, CPU Server: 112%, benchmark: 57%, p50=1.191 msec
  • benchmark   2개 -> 54688 rps, CPU Server: 221%, benchmark: 114%, p50=0.863 msec
  • benchmark   3개 -> 78307 rps, CPU Server: 280%, benchmark: 164%, p50=1.007 msec
  • benchmark   4개 -> 80022 rps, CPU Server: 278%, benchmark: 189%, p50=1.223 msec
  • benchmark   5개 -> 86145 rps, CPU Server: 296%, benchmark: 226%, p50=1.423 msec
  • benchmark   6개 -> 85520 rps, p50=1.727 msec
  • benchmark 10개 -> 74631 rps, CPU Server: 302%, benchmark: 258%, p50=3.295 msec
• benchmark 1개, 4회 실행 -> 22830 rps, CPU Server: 112%, benchmark: 57%
  • 1회 SET: 19782.79 requests per second, p50=1.191 msec, 11월 08일
  • 2회 SET: 18838.07 requests per second, p50=1.247 msec, 11월 08일
  • 3회 SET: 26352.54 requests per second, p50=0.895 msec, 11월 09일
  • 4회 SET: 26351.85 requests per second, p50=0.927 msec, 11월 09일
  • CPU 사용량 %Cpu0 : 7.1 us, 21.4 sy, 0.0 ni, 0.0 id, 60.2 wa, 4.1 hi, 7.1 si, 0.0 st %Cpu1 : 6.0 us, 23.0 sy, 0.0 ni, 0.0 id, 59.0 wa, 4.0 hi, 8.0 si, 0.0 st %Cpu2 : 4.9 us, 21.6 sy, 0.0 ni, 0.0 id, 61.8 wa, 3.9 hi, 7.8 si, 0.0 st %Cpu3 : 5.1 us, 19.2 sy, 0.0 ni, 0.0 id, 67.7 wa, 3.0 hi, 5.1 si, 0.0 st %Cpu4 : 5.0 us, 22.0 sy, 0.0 ni, 0.0 id, 62.0 wa, 3.0 hi, 8.0 si, 0.0 st %Cpu5 : 1.0 us, 8.7 sy, 0.0 ni, 81.6 id, 0.0 wa, 1.9 hi, 6.8 si, 0.0 st %Cpu6 : 1.0 us, 9.7 sy, 0.0 ni, 81.6 id, 0.0 wa, 1.9 hi, 5.8 si, 0.0 st %Cpu7 : 0.0 us, 0.0 sy, 0.0 ni,100.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu8 : 1.9 us, 13.3 sy, 0.0 ni, 74.3 id, 0.0 wa, 1.9 hi, 8.6 si, 0.0 st %Cpu9 : 0.0 us, 1.9 sy, 0.0 ni, 97.1 id, 0.0 wa, 1.0 hi, 0.0 si, 0.0 st PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2698 redis 20 0 345488 8832 7040 S 112.3 0.1 0:50.26 ping_iouring_server 2704 redis 20 0 18500 10060 3584 R 57.5 0.1 0:25.99 redis-benchmark
• benchmark 2개(동시 실행) -> 54688 rps, CPU Server: 221%, benchmark: 114%
  • SET: 27357.54 requests per second, p50=0.863 msec
  • SET: 27331.37 requests per second, p50=0.863 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2694 redis 20 0 345488 9216 6912 S 221.6 0.1 1:43.18 ping_iouring_server 2739 redis 20 0 18500 10060 3456 R 56.9 0.1 0:02.96 redis-benchmark 2740 redis 20 0 18500 10188 3584 R 56.9 0.1 0:02.53 redis-benchmark
• benchmark 3개(동시 실행) -> 78307 rps, CPU Server: 280%, benchmark: 164%
  • SET: 26232.26 requests per second, p50=1.007 msec
  • SET: 26116.48 requests per second, p50=1.007 msec
  • SET: 25959.19 requests per second, p50=1.007 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2694 redis 20 0 345488 9856 6912 S 280.4 0.1 3:50.32 ping_iouring_server 2778 redis 20 0 18500 10056 3584 R 55.9 0.1 0:10.92 redis-benchmark 2776 redis 20 0 18500 9928 3456 R 54.9 0.1 0:10.96 redis-benchmark 2777 redis 20 0 18500 10056 3584 R 52.9 0.1 0:10.91 redis-benchmark
• benchmark 4개(동시 실행) -> 80022 rps, CPU Server: 278%, benchmark: 189%
  • SET: 20198.35 requests per second, p50=1.223 msec
  • SET: 20192.64 requests per second, p50=1.215 msec
  • SET: 20129.63 requests per second, p50=1.223 msec
  • SET: 19503.44 requests per second, p50=1.215 msec
  • CPU 사용량 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2694 redis 20 0 345488 10752 6912 S 278.4 0.1 5:03.70 ping_iouring_server 2805 redis 20 0 18500 9928 3456 R 50.0 0.1 0:04.05 redis-benchmark 2806 redis 20 0 18500 9928 3456 R 48.0 0.1 0:04.03 redis-benchmark 2807 redis 20 0 18500 9932 3456 R 46.1 0.1 0:03.95 redis-benchmark 2808 redis 20 0 18500 9932 3456 R 45.1 0.1 0:04.13 redis-benchmark
• benchmark 5개(동시 실행) -> 86145 rps, CPU Server: 296%, benchmark: 226%
  • SET: 17514.36 requests per second, p50=1.423 msec
  • SET: 17409.77 requests per second, p50=1.399 msec
  • SET: 17291.46 requests per second, p50=1.407 msec
  • SET: 16989.18 requests per second, p50=1.399 msec
  • SET: 16942.26 requests per second, p50=1.407 msec
  • CPU 사용량: us+sy=463%, hi+si=428% -> CPU를 사용하는 시간과 interrupt로 대기하는 시간이 큰 차이나지 않는다. %Cpu0 : 10.3 us, 47.1 sy, 0.0 ni, 0.0 id, 4.6 wa, 17.2 hi, 20.7 si, 0.0 st %Cpu1 : 12.8 us, 46.5 sy, 0.0 ni, 0.0 id, 5.8 wa, 16.3 hi, 18.6 si, 0.0 st %Cpu2 : 12.5 us, 46.6 sy, 0.0 ni, 0.0 id, 3.4 wa, 17.0 hi, 20.5 si, 0.0 st %Cpu3 : 10.6 us, 47.1 sy, 0.0 ni, 0.0 id, 4.7 wa, 16.5 hi, 21.2 si, 0.0 st %Cpu4 : 10.8 us, 44.6 sy, 0.0 ni, 0.0 id, 7.2 wa, 16.9 hi, 20.5 si, 0.0 st %Cpu5 : 5.7 us, 33.3 sy, 0.0 ni, 17.2 id, 0.0 wa, 17.2 hi, 26.4 si, 0.0 st %Cpu6 : 6.6 us, 31.9 sy, 0.0 ni, 19.8 id, 0.0 wa, 17.6 hi, 24.2 si, 0.0 st %Cpu7 : 5.7 us, 37.5 sy, 0.0 ni, 10.2 id, 0.0 wa, 18.2 hi, 28.4 si, 0.0 st %Cpu8 : 5.6 us, 36.0 sy, 0.0 ni, 12.4 id, 0.0 wa, 19.1 hi, 27.0 si, 0.0 st %Cpu9 : 1.1 us, 10.9 sy, 0.0 ni, 22.8 id, 0.0 wa, 54.3 hi, 10.9 si, 0.0 st SUM : 82 us, 381 sy, 0.0 ni, 82.4 id, 25.7 wa, 210 hi, 218 si PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2694 redis 20 0 345488 19376 6912 S 296.1 0.2 7:31.75 ping_iouring_server 2902 redis 20 0 18500 10060 3584 R 47.6 0.1 0:05.21 redis-benchmark 2904 redis 20 0 18500 9928 3456 R 45.6 0.1 0:05.31 redis-benchmark 2905 redis 20 0 18500 10056 3584 R 44.7 0.1 0:05.24 redis-benchmark 2906 redis 20 0 18500 9928 3456 R 44.7 0.1 0:05.26 redis-benchmark 2903 redis 20 0 18500 10056 3584 R 43.7 0.1 0:05.18 redis-benchmark
• benchmark 6개(동시 실행) -> 85520 rps
  • SET: 14706.75 requests per second, p50=1.727 msec
  • SET: 14588.53 requests per second, p50=1.711 msec
  • SET: 14265.34 requests per second, p50=1.687 msec
  • SET: 14189.63 requests per second, p50=1.679 msec
  • SET: 13904.72 requests per second, p50=1.647 msec
  • SET: 13868.09 requests per second, p50=1.639 msec
• benchmark 10개(동시 실행) -> 74631 rps, CPU Server: 302%, benchmark: 258%
  • SET: 7545.46 requests per second, p50=3.295 msec
  • SET: 7515.35 requests per second, p50=3.335 msec
  • SET: 7511.45 requests per second, p50=3.287 msec
  • SET: 7495.30 requests per second, p50=3.415 msec
  • SET: 7478.42 requests per second, p50=3.351 msec
  • SET: 7447.57 requests per second, p50=3.303 msec
  • SET: 7440.86 requests per second, p50=3.287 msec
  • SET: 7420.65 requests per second, p50=3.311 msec
  • SET: 7404.61 requests per second, p50=3.239 msec
  • SET: 7376.64 requests per second, p50=3.263 msec
  • CPU 사용량: us+sy=489%, hi+si=467% -> CPU를 사용하는 시간과 interrupt로 대기하는 시간이 큰 차이나지 않는다. %Cpu0 : 12.0 us, 49.4 sy, 0.0 ni, 0.0 id, 0.0 wa, 14.5 hi, 24.1 si, 0.0 st %Cpu1 : 11.9 us, 47.6 sy, 0.0 ni, 0.0 id, 1.2 wa, 17.9 hi, 21.4 si, 0.0 st %Cpu2 : 13.1 us, 47.6 sy, 0.0 ni, 0.0 id, 0.0 wa, 15.5 hi, 23.8 si, 0.0 st %Cpu3 : 13.4 us, 46.3 sy, 0.0 ni, 0.0 id, 0.0 wa, 15.9 hi, 24.4 si, 0.0 st %Cpu4 : 13.4 us, 46.3 sy, 0.0 ni, 0.0 id, 1.2 wa, 15.9 hi, 23.2 si, 0.0 st %Cpu5 : 8.2 us, 40.0 sy, 0.0 ni, 8.2 id, 0.0 wa, 16.5 hi, 27.1 si, 0.0 st %Cpu6 : 8.2 us, 35.3 sy, 0.0 ni, 11.8 id, 0.0 wa, 18.8 hi, 25.9 si, 0.0 st %Cpu7 : 8.1 us, 36.0 sy, 0.0 ni, 10.5 id, 0.0 wa, 18.6 hi, 26.7 si, 0.0 st %Cpu8 : 8.4 us, 37.3 sy, 0.0 ni, 6.0 id, 0.0 wa, 18.1 hi, 30.1 si, 0.0 st %Cpu9 : 1.1 us, 5.4 sy, 0.0 ni, 4.3 id, 0.0 wa, 79.3 hi, 9.8 si, 0.0 st PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2694 redis 20 0 345488 22012 6912 S 302.0 0.3 9:58.12 ping_iouring_server 2938 redis 20 0 18500 10060 3584 R 28.4 0.1 0:01.09 redis-benchmark 2943 redis 20 0 18500 9928 3456 R 28.4 0.1 0:01.10 redis-benchmark 2944 redis 20 0 18500 9924 3456 R 28.4 0.1 0:01.08 redis-benchmark 2935 redis 20 0 18500 10056 3584 R 27.5 0.1 0:00.95 redis-benchmark 2940 redis 20 0 18500 10060 3584 R 27.5 0.1 0:00.98 redis-benchmark 2941 redis 20 0 18500 9928 3456 R 27.5 0.1 0:01.09 redis-benchmark 2939 redis 20 0 18500 9932 3456 R 25.5 0.1 0:01.04 redis-benchmark 2937 redis 20 0 18500 9928 3456 R 24.5 0.1 0:00.97 redis-benchmark 2942 redis 20 0 18500 9796 3328 R 21.6 0.1 0:00.91 redis-benchmark 2936 redis 20 0 18500 10060 3584 R 18.6 0.1 0:00.91 redis-benchmark

📦 Thread=10 테스트

• 서버 실행: build-dbg$ ping_iouring_server --proactor_threads=10
  
• 테스트 툴 실행: $ bin/redis-benchmark -p 6380 -t set -d 10 -n 1000000 -q
• 요약: benchmark 10개 일 때 93361 rps로 가장 높게 나왔다.
  • benchmark   1개 -> 24204 rps, p50=0.975 msec
  • benchmark   2개 -> 44896 rps, p50=0.943 msec
  • benchmark   3개 -> 61057 rps, p50=0.959 msec
  • benchmark   4개 -> 69990 rps, p50=0.783 msec
  • benchmark 10개 -> 93361 rps, CPU Server: 314%, benchmark: 269%, p50=2.655 msec
  • benchmark 20개 -> 75359 rps, p50=7.199 msec
• benchmark 1개 -> 24204 rps
  • SET: 24204.87 requests per second, p50=0.975 msec
• benchmark 2개(동시 실행) -> 44896 rps
  • SET: 22510.86 requests per second, p50=0.943 msec
  • SET: 22386.89 requests per second, p50=0.951 msec
• benchmark 3개(동시 실행) -> 61057 rps
  • SET: 20525.87 requests per second, p50=0.959 msec
  • SET: 20267.94 requests per second, p50=0.975 msec
  • SET: 20265.07 requests per second, p50=0.983 msec
• benchmark 4개(동시 실행) -> 69990 rps
  • SET: 17820.55 requests per second, p50=0.759 msec
  • SET: 17686.59 requests per second, p50=0.751 msec
  • SET: 17309.72 requests per second, p50=0.783 msec
  • SET: 17175.64 requests per second, p50=0.807 msec
• benchmark 10개(동시 실행) -> 93361 rps, CPU Server: 314%, benchmark: 269%
  • SET: 9570.57 requests per second, p50=2.639 msec
  • SET: 9449.56 requests per second, p50=2.655 msec
  • SET: 9429.96 requests per second, p50=2.639 msec
  • SET: 9369.88 requests per second, p50=2.687 msec
  • SET: 9340.56 requests per second, p50=2.655 msec
  • SET: 9314.63 requests per second, p50=2.655 msec
  • SET: 9282.90 requests per second, p50=2.655 msec
  • SET: 9248.38 requests per second, p50=2.607 msec
  • SET: 9246.33 requests per second, p50=2.647 msec
  • SET: 9114.36 requests per second, p50=2.551 msec
  • CPU 사용량: us+sy=459%, hi+si=536% -> CPU를 사용하는 시간보다 interrupt로 소비하는 시간이 더 많다. %Cpu0 : 12.9 us, 41.4 sy, 0.0 ni, 0.0 id, 0.0 wa, 14.3 hi, 31.4 si, 0.0 st %Cpu1 : 11.0 us, 41.1 sy, 0.0 ni, 0.0 id, 0.0 wa, 15.1 hi, 32.9 si, 0.0 st %Cpu2 : 10.7 us, 41.3 sy, 0.0 ni, 0.0 id, 0.0 wa, 18.7 hi, 29.3 si, 0.0 st %Cpu3 : 13.7 us, 41.1 sy, 0.0 ni, 0.0 id, 1.4 wa, 17.8 hi, 26.0 si, 0.0 st %Cpu4 : 10.8 us, 36.5 sy, 0.0 ni, 0.0 id, 2.7 wa, 20.3 hi, 29.7 si, 0.0 st %Cpu5 : 12.0 us, 38.7 sy, 0.0 ni, 0.0 id, 0.0 wa, 17.3 hi, 32.0 si, 0.0 st %Cpu6 : 11.1 us, 38.9 sy, 0.0 ni, 0.0 id, 0.0 wa, 18.1 hi, 31.9 si, 0.0 st %Cpu7 : 10.5 us, 36.8 sy, 0.0 ni, 0.0 id, 0.0 wa, 23.7 hi, 28.9 si, 0.0 st %Cpu8 : 10.8 us, 37.8 sy, 0.0 ni, 0.0 id, 0.0 wa, 18.9 hi, 32.4 si, 0.0 st %Cpu9 : 0.0 us, 2.1 sy, 0.0 ni, 0.0 id, 0.0 wa, 90.5 hi, 7.4 si, 0.0 st SUM :103.5 + 355.7 = 459.2 254.7 + 281.9 = 536.6 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2993 redis 20 0 674728 14848 6912 S 314.7 0.2 0:33.14 ping_iouring_server 3018 redis 20 0 18500 10060 3456 R 29.4 0.1 0:02.76 redis-benchmark 3021 redis 20 0 18500 10060 3456 R 29.4 0.1 0:02.76 redis-benchmark 3015 redis 20 0 18500 10056 3584 R 28.4 0.1 0:02.81 redis-benchmark 3019 redis 20 0 18500 10060 3584 R 27.5 0.1 0:02.54 redis-benchmark 3017 redis 20 0 18500 10060 3456 R 26.5 0.1 0:02.81 redis-benchmark 3020 redis 20 0 18500 10188 3584 R 26.5 0.1 0:02.81 redis-benchmark 3023 redis 20 0 18500 9804 3456 R 26.5 0.1 0:02.76 redis-benchmark 3024 redis 20 0 18500 9852 3456 R 26.5 0.1 0:02.82 redis-benchmark 3016 redis 20 0 18500 10056 3584 R 25.5 0.1 0:02.67 redis-benchmark 3022 redis 20 0 18500 10060 3584 R 23.5 0.1 0:02.77 redis-benchmark
• benchmark 20개(동시 실행) -> 75359 rps
  • SET: 3801.36 requests per second, p50=7.175 msec
  • SET: 3801.66 requests per second, p50=7.319 msec
  • SET: 3785.24 requests per second, p50=7.479 msec
  • SET: 3785.40 requests per second, p50=7.239 msec
  • SET: 3784.44 requests per second, p50=7.399 msec
  • SET: 3778.45 requests per second, p50=7.287 msec
  • SET: 3779.83 requests per second, p50=7.351 msec
  • SET: 3777.08 requests per second, p50=7.399 msec
  • SET: 3776.79 requests per second, p50=7.295 msec
  • SET: 3773.41 requests per second, p50=7.199 msec
  • SET: 3759.34 requests per second, p50=7.567 msec
  • SET: 3757.97 requests per second, p50=7.127 msec
  • SET: 3761.94 requests per second, p50=7.279 msec
  • SET: 3757.77 requests per second, p50=7.295 msec
  • SET: 3752.47 requests per second, p50=7.095 msec
  • SET: 3750.80 requests per second, p50=6.975 msec
  • SET: 3749.59 requests per second, p50=7.111 msec
  • SET: 3744.00 requests per second, p50=7.055 msec
  • SET: 3745.96 requests per second, p50=7.079 msec
  • SET: 3746.15 requests per second, p50=7.047 msec

실행 옵션

실행 옵션 보기: build-dbg$ ping_iouring_server --helpfull

• Flags from helio/examples/pingserver/ping_iouring_server.cc:
  • --http_port (Http port.); default: 8080;
  • --iouring_depth (Io uring depth); default: 512;
  • --port (Redis port); default: 6380;
  • --tls (Enable tls); default: false;
  • --tls_cert (); default: "";
  • --tls_key (); default: "";
  • --tls_verify_peer (Require peer certificate. Please note that this flag requires loading of server certificates (not sure why).); default: false;
  • --unixsocket (); default: "";
  • --use_incoming_cpu (If true uses incoming cpu of a socket in order to distribute incoming connections); default: false; (true인 경우 들어오는 연결을 분산하기 위해 소켓의 들어오는 CPU를 사용합니다.)
• Flags from helio/util/fibers/proactor_pool.cc:
  • --proactor_affinity_mode (can be on, off or auto); default: "on";
  • --proactor_threads (Number of io threads in the pool); default: 0;
• Flags from helio/util/fibers/uring_proactor.cc:
  • --enable_direct_fd (If true tries to register file descriptors); default: false;
• Flags from helio/build-dbg/_deps/abseil_cpp-src/absl/flags/parse.cc:
  • --flagfile (comma-separated list of files to load flags from); default: ;
  • --fromenv (comma-separated list of flags to set from the environment [use 'export FLAGS_flag1=value']); default: ;
  • --tryfromenv (comma-separated list of flags to try to set from the environment if present); default: ;
  • --undefok (comma-separated list of flag names that it is okay to specify on the command line even if the program does not define a flag with that name); default: ;
• Flags from helio/build-dbg/_deps/glog-src/src/logging.cc:
  • --alsologtoemail (log messages go to these email addresses in addition to logfiles); default: "";
  • --alsologtostderr (log messages go to stderr in addition to logfiles); default: false;
  • --colorlogtostderr (color messages logged to stderr (if supported by terminal)); default: false;
  • --colorlogtostdout (color messages logged to stdout (if supported by terminal)); default: false;
  • --drop_log_memory (Drop in-memory buffers of log contents. Logs can grow very quickly and they are rarely read before they need to be evicted from memory. Instead, drop them from memory as soon as they are flushed to disk.); default: true;
  • --log_backtrace_at (Emit a backtrace when logging at file:linenum.); default: "";
  • --log_dir (If specified, logfiles are written into this directory instead of the default logging directory.); default: "";
  • --log_link (Put additional links to the log files in this directory); default: "";
  • --log_prefix (Prepend the log prefix to the start of each log line); default: true;
  • --log_utc_time (Use UTC time for logging.); default: false;
  • --log_year_in_prefix (Include the year in the log prefix); default: true;
  • --logbuflevel (Buffer log messages logged at this level or lower (-1 means don't buffer; 0 means buffer INFO only; ...)); default: 0;
  • --logbufsecs (Buffer log messages for at most this many seconds); default: 30;
  • --logcleansecs (Clean overdue logs every this many seconds); default: 300;
  • --logemaillevel (Email log messages logged at this level or higher (0 means email all; 3 means email FATAL only; ...)); default: 999;
  • --logfile_mode (Log file mode/permissions.); default: 436;
  • --logmailer (Mailer used to send logging email); default: "";
  • --logtostderr (log messages go to stderr instead of logfiles); default: false;
  • --logtostdout (log messages go to stdout instead of logfiles); default: false;
  • --max_log_size (approx. maximum log file size (in MB). A value of 0 will be silently overridden to 1.); default: 1800;
  • --minloglevel (Messages logged at a lower level than this don't actually get logged anywhere); default: 0;
  • --stderrthreshold (log messages at or above this level are copied to stderr in addition to logfiles. This flag obsoletes --alsologtostderr.); default: 2;
  • --stop_logging_if_full_disk (Stop attempting to log to disk if the disk is full.); default: false;
  • --timestamp_in_logfile_name (put a timestamp at the end of the log file name); default: true;
• Flags from helio/build-dbg/_deps/glog-src/src/utilities.cc:
  • --symbolize_stacktrace (Symbolize the stack trace in the tombstone); default: true;
• Flags from helio/build-dbg/_deps/glog-src/src/vlog_is_on.cc:
  • --v (Show all VLOG(m) messages for m <= this. Overridable by --vmodule.); default: 0;
  • --vmodule (per-module verbose level. Argument is a comma-separated list of =. is a glob pattern, matched against the filename base (that is, name ignoring .cc/.h./-inl.h). overrides any value given by --v.); default: "";

서버 로그

log level 2(--v=2)로 실행했을 때 로그입니다.

📦 서버 실행

build-dbg$ ping_iouring_server --logtostderr --proactor_threads=2 --v=2

2532 init.cc:112] ping_iouring_server running in debug mode. 2532 ping_iouring_server.cc:252] main() ProactorPool pp 2532 ping_iouring_server.cc:255] main() pp.reset(depth) 2532 proactor_pool.cc:144] ProactorPool Setting pool_size(threads) to 2 2532 ping_iouring_server.cc:261] main() pp->Run() 2532 proactor_pool.cc:172] ProactorPool::Run() call SetupProactors() 2532 proactor_pool.cc:301] ProactorPool::SetupProactors() Start 2532 proactor_base.cc:535] ProactorBase::ModuleInit() Running 10 Pause() took 122us 2532 proactor_base.cc:535] ProactorBase::ModuleInit() Running 10 Pause() took 2us 2532 proactor_base.cc:112] ProactorBase Created wake_fd is 3 2532 proactor_pool.cc:364] ProactorPool::SetupProactors() call StartThread(Proactor0) 2532 pthread_utils.cc:97] Starting thread Proactor0 2532 proactor_pool.cc:379] ProactorPool::SetupProactors() Setting affinity of thread 0 on cpu 0 2532 proactor_base.cc:112] ProactorBase Created wake_fd is 4 2533 uring_proactor.cc:153] UringProactor::Init(pool_index:0, ring_size:512,wq_fd:-1) 2532 proactor_pool.cc:364] ProactorPool::SetupProactors() call StartThread(Proactor1) 2533 uring_proactor.cc:258] Create uring of size 512 2532 pthread_utils.cc:97] Starting thread Proactor1 2532 proactor_pool.cc:379] ProactorPool::SetupProactors() Setting affinity of thread 1 on cpu 1 2534 uring_proactor.cc:153] UringProactor::Init(pool_index:1, ring_size:512,wq_fd:-1) 2534 uring_proactor.cc:258] Create uring of size 512 2534 uring_proactor.cc:284] msgring supported! 2533 uring_proactor.cc:284] msgring supported! 2534 uring_proactor.cc:304] IORing with 512 entries, allocated 49216 bytes, cq_entries is 1024 2533 proactor_base.cc:142] ProactorBase::Run 2534 proactor_base.cc:142] ProactorBase::Run 2532 fiber_interface.cc:117] TL_FiberInitializer TSC Frequency : 2496000/ms 2532 scheduler.cc:115] DispatcherImpl::Run() DefaultDispatch(scheduler_) 2533 scheduler.cc:111] DispatcherImpl::Run() policy()->Run(scheduler_) 2532 scheduler.cc:140] DispatcherImpl::DefaultDispatch(sched) 2533 uring_proactor.cc:1141] UringProactor::MainLoop() Start 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 2/0 2534 scheduler.cc:111] DispatcherImpl::Run() policy()->Run(scheduler_) 2534 uring_proactor.cc:1141] UringProactor::MainLoop() Start 2533 uring_proactor.cc:1405] PRO[0] UringProactor::MainLoop() wait_for_cqe 11 2534 wait_queue.cc:57] Scheduling main from _dispatch 2534 scheduler.cc:339] Scheduler::ScheduleFromRemote() main 1 2534 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2532 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled main 1 2532 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'main' 2532 scheduler.cc:162] DispatcherImpl::DefaultDispatch() Switching to 'main' 2532 proactor_pool.cc:190] Running pool_size_:2 io threads 2532 ping_iouring_server.cc:265] main() AcceptServer acceptor(pp.get()); 2532 accept_server.cc:28] AcceptServer::AcceptServer() 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 2/0 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 12 2532 ping_iouring_server.cc:267] main() PingListener* listener = new PingListener(ctx); 2532 ping_iouring_server.cc:271] main() acceptor.AddListener(port, listener); 2532 accept_server.cc:207] AcceptServer::AddListener(ip,port) 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fibers.h:32] 2.Fiber(name, fn) 2534 fibers.h:27] 1.Fiber(fn) 2534 scheduler.cc:339] Scheduler::ScheduleFromRemote() main 1 2534 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2532 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled main 1 2532 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'main' 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 4/0 2532 scheduler.cc:162] DispatcherImpl::DefaultDispatch() Switching to 'main' 2532 fiber_interface.cc:331] Joining on 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2534 fiber_socket_base.cc:239] sock[7] Listening 7 2534 accept_server.cc:269] AddListener [7] family: 2 :6380 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2534 wait_queue.cc:57] Scheduling main from 2534 scheduler.cc:339] Scheduler::ScheduleFromRemote() main 1 2534 uring_proactor.cc:417] PRO[1] Wakeup 8/0 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2532 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled main 1 2532 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'main' 2532 scheduler.cc:162] DispatcherImpl::DefaultDispatch() Switching to 'main' 2532 fibers.cc:42] Fiber::Joined() '', DEBUG_use_count:1 2532 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 25 2532 ping_iouring_server.cc:281] main() acceptor.AddListener(http_port, new HttpListener<>); 2532 accept_server.cc:207] AcceptServer::AddListener(ip,port) 2533 uring_proactor.cc:1410] PRO[0] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2533 fibers.h:32] 2.Fiber(name, fn) 2533 fibers.h:27] 1.Fiber(fn) 2533 scheduler.cc:339] Scheduler::ScheduleFromRemote() main 1 2533 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2532 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled main 1 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 4/0 2532 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'main' 2532 scheduler.cc:162] DispatcherImpl::DefaultDispatch() Switching to 'main' 2532 fiber_interface.cc:331] Joining on 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2533 fiber_socket_base.cc:239] sock[8] Listening 8 2533 accept_server.cc:269] AddListener [8] family: 2 :8080 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2533 wait_queue.cc:57] Scheduling main from 2533 scheduler.cc:339] Scheduler::ScheduleFromRemote() main 1 2533 uring_proactor.cc:417] PRO[0] Wakeup 8/0 2532 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled main 1 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2532 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'main' 2533 uring_proactor.cc:1405] PRO[0] UringProactor::MainLoop() wait_for_cqe 24 2532 scheduler.cc:162] DispatcherImpl::DefaultDispatch() Switching to 'main' 2532 fibers.cc:42] Fiber::Joined() '', DEBUG_use_count:1 2532 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2532 ping_iouring_server.cc:283] Started http server on port 8080 2532 ping_iouring_server.cc:286] main() acceptor.Run(); 2532 accept_server.cc:118] AcceptServer::Run 2532 ping_iouring_server.cc:288] main() acceptor.Wait(); 2532 accept_server.cc:175] AcceptServer::Wait 2533 uring_proactor.cc:1410] PRO[0] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2533 fibers.h:32] 2.Fiber(name, fn) 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 6/0 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'Dispatched' 2533 listener_interface.cc:101] sock[8] AcceptServer - listening on port 8080 2533 listener_interface.cc:107] Emplacing listener 0x1401620 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 8/0 2533 uring_proactor.cc:417] PRO[0] Wakeup 8/0 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fibers.h:32] 2.Fiber(name, fn) 2533 uring_proactor.cc:1405] PRO[0] UringProactor::MainLoop() wait_for_cqe 37 2534 listener_interface.cc:107] Emplacing listener 0x1401620 2534 wait_queue.cc:57] Scheduling AcceptLoop from _dispatch 2534 scheduler.cc:339] Scheduler::ScheduleFromRemote() AcceptLoop 1 2534 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 8/0 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'Dispatched' 2534 listener_interface.cc:101] sock[7] AcceptServer - listening on port 6380 2534 listener_interface.cc:107] Emplacing listener 0x1400ee0 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 10/0 2534 uring_proactor.cc:417] PRO[1] Wakeup 8/0 2533 uring_proactor.cc:1410] PRO[0] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 38 2533 listener_interface.cc:107] Emplacing listener 0x1400ee0 2533 wait_queue.cc:57] Scheduling AcceptLoop from _dispatch 2533 scheduler.cc:339] Scheduler::ScheduleFromRemote() AcceptLoop 1 2533 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 10/0 2533 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled AcceptLoop 1 2533 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'AcceptLoop' 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2533 uring_socket.cc:139] sock[8] Accept 2533 uring_proactor.cc:1405] PRO[0] UringProactor::MainLoop() wait_for_cqe 50 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled AcceptLoop 1 2534 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'AcceptLoop' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2534 uring_socket.cc:139] sock[7] Accept 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 51

📦 redis-ecli 접속 시 서버 로그

redis-ecli -p 6380 [접속]

2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fiber_interface.cc:360] ActivateOther() Activating 'AcceptLoop' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2534 listener_interface.cc:135] sock[9] Accepted 127.0.0.1:47914 2534 ping_iouring_server.cc:181] PingListener::PickConnectionProactor() Got socket from cpu 1 2534 uring_socket.cc:139] sock[7] Accept 2534 fibers.h:64] 6.Fiber(policy, stack_alloc, name, fn, arg) 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 12/0 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'Connection' 2534 listener_interface.cc:227] sock[9] Running connection 2534 fiber_socket_base.cc:76] FiberSocketBase::Recv() 2534 uring_socket.cc:395] sock[9] UringSocket::RecvMsg() [9] 2534 uring_socket.cc:399] sock[9] UringSocket::RecvMsg() fc->PrepRecvMsg() 2534 uring_socket.cc:409] sock[9] UringSocket::RecvMsg() fc.Get() 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 65 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 uring_socket.cc:413] sock[9] UringSocket::RecvMsg() Received 22 bytes 2534 ping_iouring_server.cc:100] PingConnection::HandleRequests() Read 22 bytes 2534 uring_socket.cc:255] sock[9] WriteSome [9] 1 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 fiber_socket_base.cc:76] FiberSocketBase::Recv() 2534 uring_socket.cc:395] sock[9] UringSocket::RecvMsg() [9] 2534 uring_socket.cc:399] sock[9] UringSocket::RecvMsg() fc->PrepRecvMsg() 2534 uring_socket.cc:409] sock[9] UringSocket::RecvMsg() fc.Get() 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 80 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 uring_socket.cc:413] sock[9] UringSocket::RecvMsg() Received 17 bytes 2534 ping_iouring_server.cc:100] PingConnection::HandleRequests() Read 17 bytes 2534 uring_socket.cc:255] sock[9] WriteSome [9] 1 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 fiber_socket_base.cc:76] FiberSocketBase::Recv() 2534 uring_socket.cc:395] sock[9] UringSocket::RecvMsg() [9] 2534 uring_socket.cc:399] sock[9] UringSocket::RecvMsg() fc->PrepRecvMsg() 2534 uring_socket.cc:409] sock[9] UringSocket::RecvMsg() fc.Get() 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 95

📦 PING 명령 실행 시 서버 로그

redis-ecli> ping -> PONG

2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 uring_socket.cc:413] sock[9] UringSocket::RecvMsg() Received 14 bytes 2534 ping_iouring_server.cc:100] PingConnection::HandleRequests() Read 14 bytes 2534 uring_socket.cc:255] sock[9] WriteSome [9] 1 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 fiber_socket_base.cc:76] FiberSocketBase::Recv() 2534 uring_socket.cc:395] sock[9] UringSocket::RecvMsg() [9] 2534 uring_socket.cc:399] sock[9] UringSocket::RecvMsg() fc->PrepRecvMsg() 2534 uring_socket.cc:409] sock[9] UringSocket::RecvMsg() fc.Get() 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 110

📦 SET 명령 실행 시 서버 로그

redis-ecli> set key value -> OK

2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 uring_socket.cc:413] sock[9] UringSocket::RecvMsg() Received 33 bytes 2534 ping_iouring_server.cc:100] PingConnection::HandleRequests() Read 33 bytes 2534 uring_socket.cc:255] sock[9] WriteSome [9] 1 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 fiber_socket_base.cc:76] FiberSocketBase::Recv() 2534 uring_socket.cc:395] sock[9] UringSocket::RecvMsg() [9] 2534 uring_socket.cc:399] sock[9] UringSocket::RecvMsg() fc->PrepRecvMsg() 2534 uring_socket.cc:409] sock[9] UringSocket::RecvMsg() fc.Get() 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 125

📦 EXIT (redis-ecli 종료)

redis-ecli> exit

2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fiber_interface.cc:360] ActivateOther() Activating 'ping/1' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'ping/1' 2534 uring_socket.cc:416] sock[9] UringSocket::RecvMsg() Got 0 2534 uring_socket.cc:431] sock[9] UringSocket::RecvMsg() Error system:103 on 127.0.0.1:47914 2534 ping_iouring_server.cc:144] Connection shutting down 2534 listener_interface.cc:238] sock[9] After HandleRequests 2534 listener_interface.cc:246] sock[9] Closing connection 2534 uring_socket.cc:103] sock[9] Closing socket 2534 listener_interface.cc:79] Unlink conn, new list size: 0 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating 'ping/1' 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated 'ping/1' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying 'ping/1' 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 138

📦 서버 종료 (Ctrl+C)

2533 uring_proactor.cc:1410] PRO[0] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2533 fibers.h:32] 2.Fiber(name, fn) 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 12/0 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'Dispatched' 2533 accept_server.cc:38] Exiting on signal Interrupt 2533 accept_server.cc:363] AcceptServer::BreakListeners finished 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating 'Dispatched' 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 fibers.h:32] 2.Fiber(name, fn) 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 14/0 2534 fibers.h:32] 2.Fiber(name, fn) 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 14/0 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'Dispatched' 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating 'Dispatched' 2534 fiber_interface.cc:360] ActivateOther() Activating 'AcceptLoop' from '_dispatch' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fibers.h:43] 4.Fiber(name, fn, arg) 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 16/0 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'Dispatched' 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating 'Dispatched' 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated 'Dispatched' 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fiber_interface.cc:183] ~FiberInterface() Destroying 'Dispatched' 2533 fibers.h:43] 4.Fiber(name, fn, arg) 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 153 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 16/0 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2533 wait_queue.cc:57] Scheduling AcceptLoop from 2533 scheduler.cc:339] Scheduler::ScheduleFromRemote() AcceptLoop 1 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2533 uring_proactor.cc:417] PRO[0] Wakeup 8/0 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 fiber_interface.cc:360] ActivateOther() Activating 'AcceptLoop' from '_dispatch' 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2534 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled AcceptLoop 1 2534 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'AcceptLoop' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2534 listener_interface.cc:203] Listener - 6380 waiting for 0 connections to close 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fibers.h:43] 4.Fiber(name, fn, arg) 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fibers.h:43] 4.Fiber(name, fn, arg) 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 20/0 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2533 fibers.h:43] 4.Fiber(name, fn, arg) 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 167 2533 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 18/0 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2533 wait_queue.cc:57] Scheduling AcceptLoop from 2533 fiber_interface.cc:360] ActivateOther() Activating 'AcceptLoop' from '' 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2533 fibers.h:43] 4.Fiber(name, fn, arg) 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 20/0 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2533 listener_interface.cc:203] Listener - 8080 waiting for 0 connections to close 2533 wait_queue.cc:57] Scheduling AcceptLoop from 2533 scheduler.cc:339] Scheduler::ScheduleFromRemote() AcceptLoop 1 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2534 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 fibers.h:43] 4.Fiber(name, fn, arg) 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 22/0 2534 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled AcceptLoop 1 2534 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'AcceptLoop' 2534 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2534 listener_interface.cc:214] Listener - 6380 connections closed 2534 uring_socket.cc:103] sock[7] Closing socket 2533 fibers.h:55] 5.Fiber(policy, name, fn, arg) 2534 listener_interface.cc:219] Listener stopped for port 6380 2534 fiber_interface.cc:231] FiberInterface::Terminate() Terminating 'AcceptLoop' 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2534 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated 'AcceptLoop' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying 'AcceptLoop' 2533 fibers.h:43] 4.Fiber(name, fn, arg) 2534 uring_proactor.cc:1405] PRO[1] UringProactor::MainLoop() wait_for_cqe 180 2533 uring_proactor.cc:1248] UringProactor::MainLoop() break-1 Break after 500usec 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 22/0 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to '' 2533 wait_queue.cc:57] Scheduling AcceptLoop from 2533 fiber_interface.cc:360] ActivateOther() Activating 'AcceptLoop' from '' 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating '' 2533 uring_proactor.cc:1286] UringProactor::MainLoop() Switching to 'AcceptLoop' 2533 listener_interface.cc:214] Listener - 8080 connections closed 2533 uring_socket.cc:103] sock[8] Closing socket 2533 listener_interface.cc:219] Listener stopped for port 8080 2533 wait_queue.cc:57] Scheduling main from AcceptLoop 2533 scheduler.cc:339] Scheduler::ScheduleFromRemote() main 1 2533 fiber_interface.cc:231] FiberInterface::Terminate() Terminating 'AcceptLoop' 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated 'Dispatched' 2533 fiber_interface.cc:183] ~FiberInterface() Destroying 'Dispatched' 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated 'Dispatched' 2533 fiber_interface.cc:183] ~FiberInterface() Destroying 'Dispatched' 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2533 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2533 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2532 scheduler.cc:482] Scheduler::ProcessRemoteReady() Pulled main 1 2532 scheduler.cc:520] Scheduler::ProcessRemoteReady() set ready 'main' 2532 scheduler.cc:162] DispatcherImpl::DefaultDispatch() Switching to 'main' 2532 accept_server.cc:180] AcceptServer::Wait completed 2533 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated '' 2533 fiber_interface.cc:183] ~FiberInterface() Destroying '' 2532 ping_iouring_server.cc:291] main() pp->Stop(); 2532 proactor_base.cc:175] Proactor::StopFinish 2532 proactor_base.cc:175] Proactor::StopFinish 2532 proactor_pool.cc:204] Proactors have been stopped 2533 scheduler.cc:397] Scheduler::DestroyTerminated() Releasing terminated 'AcceptLoop' 2534 uring_proactor.cc:1410] PRO[1] UringProactor::MainLoop() Woke up after wait_for_cqe 2533 fiber_interface.cc:183] ~FiberInterface() Destroying 'AcceptLoop' 2534 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 24/0 2534 uring_proactor.cc:417] PRO[1] Wakeup 8/0 2534 uring_proactor.cc:1399] UringProactor::MainLoop() break-2 2534 uring_proactor.cc:1418] PRO[1] total/stalls/cqe_fetches/num_submits: 192/13/17/16 2534 uring_proactor.cc:1421] PRO[1] AvgCqe/ReapCall: 1.29412 2534 uring_proactor.cc:1422] PRO[1] tq_wakeups/tq_wakeup_saved/tq_full/tq_task_int: 7/8/0/3 2534 uring_proactor.cc:1425] PRO[1] busy_sq/get_entry_sq_full/get_entry_sq_err/get_entry_awaits/ pending_callbacks: 0/0/0/0 2534 uring_proactor.cc:1429] PRO[1] centries size: 512 2533 uring_proactor.cc:1253] UringProactor::MainLoop() Tasks runs 24/1 2534 scheduler.cc:119] Dispatcher exiting, switching to main_cntx 2533 uring_proactor.cc:1399] UringProactor::MainLoop() break-2 2534 scheduler.cc:93] ~DispatcherImpl 2534 fiber_interface.cc:183] ~FiberInterface() Destroying '_dispatch' 2534 fiber_interface.cc:183] ~FiberInterface() Destroying 'main' 2533 uring_proactor.cc:1418] PRO[0] total/stalls/cqe_fetches/num_submits: 70/4/5/8 2533 uring_proactor.cc:1421] PRO[0] AvgCqe/ReapCall: 2.4 2533 uring_proactor.cc:1422] PRO[0] tq_wakeups/tq_wakeup_saved/tq_full/tq_task_int: 4/9/0/4 2533 uring_proactor.cc:1425] PRO[0] busy_sq/get_entry_sq_full/get_entry_sq_err/get_entry_awaits/ pending_callbacks: 0/0/0/0 2533 uring_proactor.cc:1429] PRO[0] centries size: 512 2533 scheduler.cc:119] Dispatcher exiting, switching to main_cntx 2533 scheduler.cc:93] ~DispatcherImpl 2533 fiber_interface.cc:183] ~FiberInterface() Destroying '_dispatch' 2533 fiber_interface.cc:183] ~FiberInterface() Destroying 'main' 2532 proactor_pool.cc:210] Thread 0 has joined 2532 proactor_pool.cc:210] Thread 1 has joined 2532 listener_interface.cc:223] Destroying ListenerInterface 0x1400ee0 2532 listener_interface.cc:223] Destroying ListenerInterface 0x1401620 2532 uring_proactor.cc:145] Closing wake_fd 3 ring fd: 5 2532 uring_proactor.cc:145] Closing wake_fd 4 ring fd: 6 WARNING: Logging before InitGoogleLogging() is written to STDERR 2532 scheduler.cc:119] Dispatcher exiting, switching to main_cntx 2532 scheduler.cc:93] ~DispatcherImpl 2532 fiber_interface.cc:183] ~FiberInterface() Destroying '_dispatch' 2532 fiber_interface.cc:183] ~FiberInterface() Destroying 'main'

소스 설명

소스는 다음 3개 파일로 구성됩니다.

• ping_iouring_server.cc (269줄): main()이 있음.
• resp_parser.h (82줄): RESP 파서 헤더 파일
• resp_parser.cc (358줄): RESP 파서 C++ 파일

RESP는 REdis Serialization Protocol의 약자(略字)입니다. RESP는 레디스 서버와 클라이언트(예: redis-cli, lettuce(Java Library)), 서버와 서버(마스터-복제) 간에 통신할 때 사용하는 형식(format)/규약(protocol)입니다. 특수문자를 포함할 수 있습니다. 즉 binary safe 합니다.
RESP에 대한 자세한 설명은 여기를 참조하세요.

📦 resp_parser.h

제로 카피 파서(zero-copy parser)입니다. 사용자는 'RespExpr'에 계속 액세스하는 동안 파서가 'COMMAND_READY'를 반환하는 경우 'str'을 무효화해서는 안 됩니다. 그러나 파서가 'MORE_INPUT'을 반환하는 경우 파서는 '소비된(consumed)' 결과에 따라 내부적으로 중간 상태를 캐시하므로 사용자는 'str'을 무효화할 수 있습니다. 파서는 최소 임계값 미만이 전달되고 'COMMAN_READY'에 도달하지 않은 경우 문자열 또는 그 일부를 사용한다고 보장하지 않습니다.

It's a zero-copy parser. A user should not invalidate str if the parser returns COMMAND_READY as long as he continues accessing RespExpr. However, if parser returns MORE_INPUT a user may invalidate str because parser caches the intermediate state internally according to 'consumed' result. A parser does not guarantee to consume the string or part of it if less than a minimal threshold was passed and COMMAN_READY is not reached.

주요한 정의들

• enum ParseResult : uint8_t { OK, MORE, INVALID, };
• enum State : uint8_t { START = 0, INLINE, ARRAY_LEN, PARSE_ARG, BULK_STR, FINISH_ARG, CMD_COMPLETE, };
• State state_ = START; (초기값)
• enum Status { RESP_OK, MORE_INPUT, INVALID_ARRAYLEN, INVALID_BULKLEN, INVALID_STRING, INVALID_INT };
• Status last_status_ = RESP_OK; (초기값)

📦 resp_parser.cc

redis-cli에서 "SET KEY VALUE"를 입력하면 resp 포멧으로 아래와 같이 변경되어 서버에 전달됩니다.
"*3<CR><LF>$3<CR><LF>SET<CR><LF>$3<CR><LF>KEY<CR><LF>$5<CR><LF>VALUE<CR><LF>"
<CR>는 carriage return(\r)을 나타내고, <LF>는 line feed(\n)를 나타냅니다.

아래 RespParser::Parse() 함수는 resp 포멧으로 변경된 문자열을 처리(parsing)합니다.

RespParser::Parse() 함수 소스 요약

if (state_ == START) { InitStart(str[0], res); } while (state_ != CMD_COMPLETE) { switch (state_) { case ARRAY_LEN: ConsumeArrayLen(str); -> multibulk(*) 포멧: *3<CR><LF> -> state_ = PARSE_ARG case PARSE_ARG: ParseArg(str); -> bulk($) 포멧: $3<CR><LF>SET<CR><LF> -> state_ = BULK_STR case BULK_STR: ConsumeBulk(str); 포멧: SET<CR><LF> -> state_ = FINISH_ARG case FINISH_ARG: HandleFinishArg(); -> state_ = PARSE_ARG/CMD_COMPLETE case INLINE: ParseInline(str); -> 포멧: +,- -> state_ = CMD_COMPLETE } }

처리과정 설명

1. 처음에 InitStart()를 호출해서 '*'를 확인하고 state_ = ARRAY_LEN;
   
2. switch에서 ARRAY_LEN 이면 ConsumeArrayLen()를 호출해서 '3'을 추출해서 저장하고 state_ = PARSE_ARG;
   
3. PARSE_ARG 이면 ParseArg()를 호출해서 '$3'에서 '3'을 추출하고 state_ = BULK_STR;
   
4. BULK_STR 이면 ConsumeBulk()를 호출해서 'SET'을 추출하고 state_ = FINISH_ARG;
   
5. FINISH_ARG 이면 HandleFinishArg()를 호출해서 데이터(문자열)이 더 있으면 state_ = PARSE_ARG; 없으면 state_ = CMD_COMPLETE;
6. state_ == PARSE_ARG 이면 3.으로 가서 "$3<CR><LF>KEY<CR><LF>"를 계속 처리하고 state_ = CMD_COMPLETE 이면 while()을 종료한다.

RESP(REdis Serialization Protocol) 구분자 설명

• 클라이언트가 서버로 명령을 보낼 때 구분자: 서버에서 받아서 처리
  • multibulk: 구분자 '*' 배열을 표시 포멧: *3<CR><LF> -> ConsumeArrayLen()
  • bulk: 구분자 '$' 특수문자가 포함된 문자열 포멧: $3<CR><LF>KEY<CR><LF> -> ParseArg()
• 서버가 클라이언트로 응답을 보낼 때 구분자: 클라이언트에서 받아서 처리
  • integer: 구분자 ':' 정수 표시 포멧: :1234<CR><LF>
  • inline: 구분자 '+','-' 단순 문자열 표시 포멧: +OK<CR><LF>, +PONG<CR><LF>, -ERR no such key<CR><LF>

함수 리스트

• auto RespParser::Parse(Buffer str, uint32_t* consumed, vector<Buffer>* res) -> Status { ... }
• void RespParser::InitStart(uint8_t prefix_b, vector<Buffer>* res)
• void RespParser::CacheState(vector<Buffer>* res)
• auto RespParser::ParseInline(Buffer str) -> Status { ... } -> INLINE: +,-
• auto RespParser::ParseNum(Buffer str, int64_t* res) -> ParseResult { ... } -> 숫자 추출
• auto RespParser::ConsumeArrayLen(Buffer str) -> Status { ... } -> ARRAY_LEN: multibulk(*)
• auto RespParser::ParseArg(Buffer str) -> Status { ... } -> PARSE_ARG: bulk($),integer(:)
• auto RespParser::ConsumeBulk(Buffer str) -> Status { ... } -> BULK_STR
• void RespParser::HandleFinishArg() -> FINISH_ARG
• void RespParser::ExtendLastString(Buffer str)

📦 ping_iouring_server.cc

◎ main() 함수 요약

int main(int argc, char* argv[]) { unique_ptr<util::ProactorPool> pp; // ProactorPool pp 선언 pp.reset(Pool::IOUring(GetFlag(FLAGS_iouring_depth))); // pp IOUring 사용 설정 pp->Run(); // pp 시작 AcceptServer acceptor(pp.get()); PingListener* listener = new PingListener(ctx); // PingListener 생성 acceptor.AddListener(port:6380, listener); // 6380 Listen 시작 uint16_t port = acceptor.AddListener(http_port:8080, new HttpListener<>); // 8080 Listen 시작 acceptor.Run(); acceptor.Wait(); pp->Stop(); }

◎ PingListener 클래스 요약

class PingListener : public ListenerInterface { public: PingListener(SSL_CTX* ctx) : ctx_(ctx) { } ~PingListener() { SSL_CTX_free(ctx_); } virtual Connection* NewConnection(ProactorBase* context) final { return new PingConnection(ctx_); } ProactorBase* PickConnectionProactor(FiberSocketBase* sock) final; private: SSL_CTX* ctx_; };

◎ PingListener 클래스 PickConnectionProactor() 함수 요약

ProactorBase* PingListener::PickConnectionProactor(FiberSocketBase* sock) { #ifdef __linux__ int fd = sock->native_handle(); int cpu; socklen_t len = sizeof(cpu); CHECK_EQ(0, getsockopt(fd, SOL_SOCKET, SO_INCOMING_CPU, &cpu, &len)); VLOG(1) << "Got socket from cpu " << cpu; bool use_incoming = GetFlag(FLAGS_use_incoming_cpu); if (use_incoming) { vector<unsigned> ids = pool()->MapCpuToThreads(cpu); if (!ids.empty()) { return pool()->at(ids.front()); } } #endif return pool()->GetNextProactor(); }

◎ PingConnection 클래스 요약

class PingConnection : public Connection { public: PingConnection(SSL_CTX* ctx) : ctx_(ctx) { } void Handle(int res, int32_t payload, ProactorBase* mgr); private: void HandleRequests() final; SSL_CTX* ctx_ = nullptr; };

◎ PingConnection 클래스 HandleRequests() 함수 요약

여기서 resp_parser.Parse()를 호출해서 파싱하고 'PONG' 또는 'OK'를 리턴한다. void PingConnection::HandleRequests() { ThisFiber::SetName(absl::StrCat("ping/", conn_id.fetch_add(1, memory_order_relaxed))); system::error_code ec; unique_ptr<tls::TlsSocket> tls_sock; if (ctx_) { // SSL_CTX* ctx = SSL_CTX_new(TLS_server_method()); tls_sock.reset(new tls::TlsSocket(std::move(socket_))); tls_sock->InitSSL(ctx_); FiberSocketBase::AcceptResult aresult = tls_sock->Accept(); socket_ = std::move(tls_sock); if (!aresult) { LOG(ERROR) << "Error handshaking " << aresult.error().message(); return; } else { LOG(INFO) << "TLS handshake succeeded"; } } FiberSocketBase* peer = tls_sock ? (FiberSocketBase*)tls_sock.get() : socket_.get(); AsioStreamAdapter<FiberSocketBase> asa(*peer); base::IoBuf io_buf{1024}; RespParser resp_parser; uint32_t consumed = 0; vector<RespParser::Buffer> args; while (true) { auto dest = io_buf.AppendBuffer(); asio::mutable_buffer mb(dest.data(), dest.size()); size_t res = asa.read_some(mb, ec); if (FiberSocketBase::IsConnClosed(ec)) break; CHECK(!ec) << ec << "/" << ec.message(); VLOG(1) << "Read " << res << " bytes"; io_buf.CommitWrite(res); RespParser::Status st = resp_parser.Parse(io_buf.InputBuffer(), &consumed, &args); io_buf.ConsumeInput(consumed); if (st == RespParser::RESP_OK) { if (args.empty()) continue; ToUpper(&args[0]); std::string_view cmd = ToAbsl(args.front()); if (cmd == "PING") { ping_qps.Inc(); const char kReply[] = "+PONG\r\n"; auto b = boost::asio::buffer(kReply, sizeof(kReply) - 1); asa.write_some(b, ec); if (ec) { break; } } else { const char kReply[] = "+OK\r\n"; auto b = boost::asio::buffer(kReply, sizeof(kReply) - 1); asa.write_some(b, ec); if (ec) { break; } } } else if (st == RespParser::MORE_INPUT) { continue; } else { break; } } VLOG(1) << "Connection shutting down"; error_code err = socket_->Shutdown(SHUT_RDWR); LOG_IF(WARNING, err) << "Shutdown failed: " << err.message(); }

---