온프레미스 서버 응답 속도 개선

[SolfE]

현재 온프레미스 서버로 마이그레이션 이후 응답시간이 매우 늦습니다. 이를 개선해야 합니다.

메인화면과 아티클 페이지 모두 최소 6초~12초 이상 지연 Books의 경우 3초 정도의 지연이 발생합니다. (프로메테우스, 그라파나 측정 한국 기준)
그라파나 측정 시간은 서버 내부 처리 시간이므로 네트워크 보다는 다른 원인이 의심됩니다.

[SolfE]

예상 원인

1. 메모리, CPU 할당량 부족(OS, 컨테이너, JVM 레벨)
2. cpu 아키텍쳐 오버헤드 (cpu 아키텍쳐 차이로 인한 번역 시간)
3. Disk IO (microSD로 인한)
4. 네트워크 지연
5. 외부 서비스 RTT 지연 (AWS Bedrock, S3)/

[SolfE]

리소스

하드웨어 기준

cpu는 id(유휴상태)가 많은 것으로 보아 여유롭다.
메모리의 경우 다소 사용량이 아슬아슬하지만 요청이 몰리지 않는다면 병목까지 되기는 어려워 보인다.

top -H -p $(pgrep -f app.jar | head -n1)
top - 15:58:22 up 1 day,  3:23,  3 users,  load average: 0.00, 0.02, 0.05
Threads:  74 total,   0 running,  74 sleeping,   0 stopped,   0 zombie
%Cpu(s):  8.4 us,  4.6 sy,  0.0 ni, 85.9 id,  0.8 wa,  0.0 hi,  0.3 si,  0.0 st
MiB Mem :   1846.8 total,    116.5 free,    982.9 used,    833.9 buff/cache
MiB Swap:    512.0 total,    242.2 free,    269.8 used.    863.9 avail Mem

$ vmstat 1 10
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 2  0 355328 130448  58416 894864    0    1     6    14  139  197  1  0 98  0  0
 1  0 355328 130448  58416 894864    0    0     0    28 4239 5940  3  3 93  0  0
 1  0 355328 130448  58416 894864    0    0     0     0 2861 4283  2  2 96  0  0
 2  0 355328 130448  58416 894864    0    0     0    68 2611 3533  3  1 96  0  0
 1  0 355328 130448  58416 894864    0    0     0     0 4641 6434  3  2 95  0  0
 1  0 355328 130448  58416 894864    0    0     0     0 5816 8626  3  3 94  0  0
 1  0 355328 130448  58416 894864   44    0    44     0 7105 8258  8  4 88  0  0
 1  0 355328 130448  58416 894864    0    0     0     0 4681 5993  2  2 97  0  0
 2  0 355328 130448  58416 894864    0    0     0     0 4974 6275  2  2 96  0  0
 1  0 355328 130448  58416 894864 2952    0  2952    44 4235 5699 12  2 81  6  0
 1  0 355328 130448  58416 894864    0    0     0     0  519  781  1  0 100  0  0
 1  0 355328 130448  58416 894864    0    0     0     0  334  507  1  0 99  0  0
 1  0 355328 130448  58416 894864    0    0     8    20  559  787  3  1 97  0  0
 1  0 355328 130448  58416 894864    0    0     0     0 1642 2279  1  1 98  0  0
 1  0 355328 130448  58416 894864    0    0     0    20 1576 2433  2  2 97  0  0
 2  0 355328 130448  58416 894864    0    0     0     0 1475 2180  1  1 98  0  0
 1  0 355328 130448  58416 894864    0    0     0     0  621 1000  1  0 99  0  0
 2  0 355328 130448  58416 894864    0    0     0     0  344  524  1  0 99  0  0
 1  0 355328 130448  58416 894864    0    0     0     0  316  491  1  0 99  0  0
 1  0 355328 130448  58416 894864    0    0     0     0  450  713  1  0 99  0  0

$ free -h
               total        used        free      shared  buff/cache   available
Mem:           1.8Gi       965Mi       130Mi        18Mi       837Mi       880Mi
Swap:          511Mi       269Mi       242Mi

컨테이너 수준

제한이 따로 존재하지 않았다.

docker inspect server --format 'NanoCPUs={{.HostConfig.NanoCPUs}} Memory={{.HostConfig.Memory}}'
NanoCPUs=0 Memory=0

JVM 수준

약 컨테이너 메모리의 1/4정도만 힙으로 사용중

docker exec -it server java -XshowSettings:vm -version | head -n 20
VM settings:
    Max. Heap Size (Estimated): 462.00M 

그라파나 모니터링결과 25% 평균 사용률로 부족하지 않음

[SolfE]

CPU 아키텍쳐 설정

라즈베리파이 서버는 ARM 기반 프로세서를 사용하고 있다. aarch64

컨테이너 buildx 정상

$ docker exec server uname -m 
aarch64

JVM 기준으로도 프로세서 동일

$ docker exec server java -XshowSettings:properties -version | grep 'os.arch'
os.arch = aarch64

오버헤드가 존재하지 않으며 QEMU 에뮬레이션 이슈는 아닌 것으로 확인.

[SolfE]

MicroSD DISK IO 지연

sysstat 패키지를 활용해서 디스크 IO 지연을 모니터링했습니다.

주요 지표인 iowait 0.3%, r_await 10ms 미만으로 크게 지연되지 않습니다.

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.28    0.00    0.44    0.32    0.00   97.97

Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
mmcblk0          0.68     24.84     0.30  30.61    9.69    36.43    6.40     55.63     4.75  42.60   42.86     8.70    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00    0.28   1.53

[SolfE]

서버 네트워크 점검

curl을 통해 지연시간을 측정했습니다.

주요 실험결과 cloudflare 서비스를 제외하고 측정한 상황에서 응답시간 개선

• DNS + TCP 연결 : 0.19s
• time_starttransfer(서버가 첫 번째 바이트를 보내기 시작한 시간) : 1.42s -> 0.18s
• 다운로드 완료시간 : 1.42s -> 0.18s
  즉 네트워크가 아닌 서버 처리 시간이 매우 느립니다.

curl -w '%{time_connect} %{time_starttransfer} %{time_total}\n' https://api.linglevel.com
0.193700 1.421410 1.421525

직접 Cloudflare 없이 IP로 요청 (Cloudflare 지연 비교)
0.163292 0.186188 0.186242

서버 내부에서 도커 컨테이너 DNS를 통해 직접  호출 (Nginx Proxy Manager 지연 비교)
0.000642 0.121656 0.121792

조치 1 : CloudFlare 프록시 제거

해당 명령어를 통해 헤더를 분석후 CF를 경유하고 있는지 확인

curl -I https://api.linglevel.com

비경유 조치 후 시간

0.012518 0.048237 0.048269

CloudFlare 을 경유하게되면 0.7초 정도의 응답 시간이 소요됌을 확인했다.

[SolfE]

외부 서비스 지연 측정

Redis 지연 측정 밑에 모니터링 설정 후 API를 사용하더라도 눈에 띄는 지연 없음

CONFIG SET latency-monitor-threshold 100

Dave, no latency spike was observed during the lifetime of this Redis instance, not in the slightest bit. I honestly think you ought to sit down calmly, take a stress pill, and think things over.

MongoDB (단 커넥션 풀이 아닌 커넥션을 포함한 시간)
눈에 띄는 지연 없음

$ time mongosh "~~~" --eval 'db.adminCommand({ping:1})'
{ ok: 1 }
mongosh  --eval 'db.adminCommand({ping:1})'  0.46s user 0.07s system 51% cpu 1.016 total

[SolfE]

슬로우 쿼리 측정

현재 굉장히 느린 API의 공통점은 연산에 메모리 사용량이 많은 것이다.

대표적인 예시로 아티클 목록을 가져오는 요청을 테스트 해보았다.

mongosh 실행결과

db.articles.find().sort({createdAt:-1}).limit(100).explain("executionStats");
~~~
optimizationTimeMillis: 0,
~~~

즉 쿼리 문제는 아닌 것으로 보인다.

[SolfE]

가설 : 컴퓨터 리소스(메모리) 부족에 의한 SWAP 영역사용 딜레이

JVM 그라파나 모니터링으로 보는 어플리케이션 레벨에서는 공간이 남았지만, Heap을 할당하기 위해 OS레벨에서 일부 스왑영역을 할당하고 있을경우 MicroSD 카드로 인한 IO 지연이 필연적이다.

docker exec server sh -c 'pid=$(pgrep -f app.jar | head -n1); cat /proc/$pid/status | egrep "VmRSS|VmSwap"'
VmRSS:	  567696 kB
VmSwap:	   39552 kB

실제로 할당은 하고 있었지만 다소 빈약했다.

그러던 와중 갑자기 iostat에서 util이 100퍼 센트가 되는 현상이 포작됐다.

Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz     f/s f_await  aqu-sz  %util
mmcblk0          0.00      0.00     0.00   0.00    0.00     0.00    8.00     36.00     0.00   0.00 1534.75     4.50    0.00      0.00     0.00   0.00    0.00     0.00    0.00    0.00   12.28 100.00

이는 스토리지 레이턴시 스파이크라는 현상이라고 한다. 그러나 이는 간헐적인 현상이라 제외

[SolfE]

최종 가설 : 연산처리 속도 부족

의외로 CPU 성능이 문제였다.

curl을 통해 api에서 아티클의 개수를 늘려가며 데이터를 가져와 보니 선형적으로 시간이 비례했다.
이는 DB를 조회하거나 DB에서 가져온 데이터가 크기 때문이라기 보다 처리해야하는 연산이 많아서 일 수 있다.
Articles

limit	total(s)	비고
1	미측정 (참고: limit=0 → 1.647s)
10	1.599
100	7.171
200	6.357 / 6.696 (avg≈6.53)

ping의 경우 문제없이 30ms대의 응답을 보였으며, 단 개수가 많은 피드를 조회하는 쿼리를 날리자 3000ms대의 응답을 보였다. 다른환경에서 측정하면 1/10 수준의 시간이 나온다.

라즈베리파이

mongosh "$MONGODB_URI" --eval '
  const t0 = Date.now();
  const feeds = db.feeds.find({deleted:false}).toArray();
  print("feeds fetch all elapsed(ms):", Date.now()-t0, "count:", feeds.length);
  '
feeds fetch all elapsed(ms): 2866 count: 3881

Macbook

mongosh "$MONGODB_URI" --eval '
  const t0 = Date.now();
  const feeds = db.feeds.find({deleted:false}).toArray();
  print("feeds fetch all elapsed(ms):", Date.now()-t0, "count:", feeds.length);
  '
feeds fetch all elapsed(ms): 672 count: 3881

이는 몽고쉘(JS)에서 도는 코드기에 네트워크 RTT, TLS 핸드셰이크/복호화, BSON→JS 역직렬화, CPU 속도 같은 변수들이 반영된다. 즉 스왑 영역 보다는 CPU 연산처리 속도(점유율 X 싱글코어 연산 점유율)에 의한 것으로 보인다. 실제로 하나의 코어가 80%까지 부하를 받고, 나머지 코어에 분산되었다가 사라진다.

[SolfE]

결론 : 최적화 방법

1. 라즈베리파이 이상의 서버를 산다. (CPU성능이 상대적으로 높고(핵심 문제), 메인 메모리 여유 공간이 확보되며, MicroSD말고 제대로 된 SSD 구성)
2. DB 쿼리를 최적화 한다. (아티클과 피드 모두 적절한 크기의 배치 쿼리로 페이지네이션을 10개 단위로 구성)