멀티코어에서 처리량이 코어 수만큼 늘지 않고 어느 지점부터 오히려 떨어질 때, 원인이 락 경합(lock contention)인 경우가 많다. perf lock은 배포판 커널 그대로도 쓸 수 있어 편하지만 트레이스포인트를 기록하는 방식이라 “측정하는 동안 일어난 일”을 본다. 반면 커널이 락 하나하나에 대해 누적으로 몇 번 기다렸고 총 얼마나 기다렸는지, 그리고 어느 소스 위치에서 기다렸는지를 직접 세어두게 하려면 CONFIG_LOCK_STAT이 필요하다. 이 글에서는 커널에 lockstat을 켜는 방법과 /proc/lock_stat 출력을 읽는 법을, 실제로 경합을 만들어 측정한 결과로 정리한다.
lockstat이 보여주는 것
lockstat은 lockdep이 이미 락 함수에 박아둔 훅을 재활용해서, 락 클래스(lock class) 단위로 통계를 누적한다. 같은 도구 계열이지만 목적이 다르다.
| 보는 것 | 배포판 커널 | |
|---|---|---|
lockdep (PROVE_LOCKING) | 락 획득 순서가 데드락을 만들 수 있는지 | 꺼져 있음 |
lockstat (LOCK_STAT) | 락별 경합 횟수·대기 시간·보유 시간의 누적 통계 | 꺼져 있음 |
| perf lock | 측정 구간 동안의 경합 이벤트 | 그대로 사용 가능 |
lockstat이 주는 값은 클래스마다 con-bounces, contentions, 대기 시간(min/max/total/avg), acq-bounces, acquisitions, 보유 시간(min/max/total/avg)이다. 여기에 더해 클래스당 경합 지점(contention point) 네 개를 따로 기록한다 — 락을 기다리게 만든 호출 위치다.
커널 설정 — LOCK_STAT 하나만 켜면 된다
흔히 PROVE_LOCKING까지 같이 켜야 한다고 알려져 있는데, Kconfig를 보면 그럴 필요가 없다. LOCK_STAT이 필요한 것을 전부 select한다.
config LOCK_STAT
bool "Lock usage statistics"
depends on DEBUG_KERNEL && LOCK_DEBUGGING_SUPPORT
select LOCKDEP
select DEBUG_SPINLOCK
select DEBUG_MUTEXES if !PREEMPT_RT
select DEBUG_RT_MUTEXES if RT_MUTEXES
select DEBUG_LOCK_ALLOC
default n커널 7.1.8 소스에 x86_64 기본 설정을 얹고 LOCK_STAT만 켜서 확인해봤다.
curl -O https://cdn.kernel.org/pub/linux/kernel/v7.x/linux-7.1.8.tar.xz
tar xf linux-7.1.8.tar.xz && cd linux-7.1.8
make x86_64_defconfig
scripts/config --enable DEBUG_KERNEL --enable LOCK_STAT \
--enable BLK_DEV_INITRD --enable DEVTMPFS --enable DEVTMPFS_MOUNT
make olddefconfig
make -j$(nproc) bzImage$ grep -E '^CONFIG_(LOCK_STAT|LOCKDEP|DEBUG_SPINLOCK|DEBUG_MUTEXES|DEBUG_LOCK_ALLOC|DEBUG_KERNEL)=' .config
CONFIG_DEBUG_KERNEL=y
CONFIG_LOCK_STAT=y
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_MUTEXES=y
CONFIG_DEBUG_LOCK_ALLOC=y
CONFIG_LOCKDEP=y
$ grep PROVE_LOCKING .config
# CONFIG_PROVE_LOCKING is not setLOCKDEP과 디버그 락 구현이 자동으로 딸려 들어왔고, 데드락 검증기인 PROVE_LOCKING은 꺼진 채로 남는다. 통계만 필요하면 이 상태가 오버헤드가 더 작다.
인터페이스 — 파일 두 개
| 경로 | 동작 |
|---|---|
/proc/sys/kernel/lock_stat | 1 쓰면 수집 시작, 0 쓰면 중지 |
/proc/lock_stat | 읽으면 현재 통계, 0을 쓰면 통계 초기화 |
통계는 부팅 직후부터 계속 누적되므로, 무언가를 측정하려면 워크로드 직전에 반드시 초기화해야 한다. 부팅 로그 단계의 경합이 그대로 섞여 들어오면 원하는 지점이 묻힌다.
echo 0 > /proc/lock_stat # 초기화
echo 1 > /proc/sys/kernel/lock_stat # 수집 시작
# ... 워크로드 실행 ...
echo 0 > /proc/sys/kernel/lock_stat # 수집 중지
cat /proc/lock_stat실측 — 같은 디렉터리를 네 프로세스가 두드릴 때
디렉터리 하나에 대해 여러 프로세스가 동시에 mkdir/rmdir을 하면 그 디렉터리 아이노드의 락에서 직렬화가 일어난다. 앞서 빌드한 커널을 busybox initramfs와 함께 QEMU로 띄워 측정했다.
mount -t proc none /proc
mount -t devtmpfs none /dev
mount -t tmpfs none /tmp
echo 0 > /proc/lock_stat
echo 1 > /proc/sys/kernel/lock_stat
mkdir -p /tmp/hot
for i in 0 1 2 3; do
(
n=0
while [ $n -lt 1500 ]; do
mkdir /tmp/hot/p${i}_$n 2>/dev/null
rmdir /tmp/hot/p${i}_$n 2>/dev/null
n=$((n + 1))
done
) &
done
wait
echo 0 > /proc/sys/kernel/lock_statqemu-system-x86_64 -smp 4 -m 1024 -nographic \
-kernel arch/x86/boot/bzImage \
-initrd initramfs.cpio.gz \
-append "console=ttyS0 rdinit=/init loglevel=4"수집이 켜져 있는지부터 확인한다. lock_stat sysctl은 CONFIG_LOCK_STAT이 있으면 기본값이 1이다.
### 인터페이스 확인
-rw------- 1 0 0 0 Aug 14 12:50 /proc/lock_stat
-rw-r--r-- 1 0 0 0 Aug 14 12:50 /proc/sys/kernel/lock_stat
lock_stat sysctl = 1워크로드가 끝난 뒤 경합이 실제로 발생한 항목만 골라 봤다. 전체 출력은 경합이 0인 클래스까지 전부 나열하므로 그대로 보면 길다.
$ head -n 4 /proc/lock_stat
lock_stat version 0.4
-----------------------------------------------------------------------------------------------------------------------------------
class name con-bounces contentions waittime-min waittime-max waittime-total waittime-avg acq-bounces acquisitions holdtime-min holdtime-max holdtime-total holdtime-avg
-----------------------------------------------------------------------------------------------------------------------------------
$ awk 'NR>4 && $2 ~ /^[0-9]+$/ && $3+0 > 0' /proc/lock_stat
&type->i_mutex_dir_key#4/1: 991 20 35.95 8050.59 37845.05 1892.25 8753 12001 0.00 10993.61 134786.78 11.23
tasklist_lock-W: 2367 5 35.66 1048.55 2617.06 523.41 22759 36017 0.00 6160009.89 14416189.22 400.26
tasklist_lock-R: 1985 15 34.85 3132.79 14271.02 951.40 16949 35978 0.00 3223.07 8124.38 0.23
&p->pi_lock: 22 10 36.25 969.48 3478.25 347.83 30101 85643 0.00 10394016.29 29098408.36 339.76
rcu_node_0: 40 10 14.04 541.09 1159.77 115.98 2417 7465 0.00 869.97 34049.05 4.56
&rq->__lock: 2247 8 70.06 10394016.29 10395504.85 1299438.11 32034 629609 0.00 10394016.29 29368258.07 46.65
&anon_vma->rwsem: 2408 6 419.05 3715.09 8838.21 1473.04 95916 180264 0.00 27996.49 51304.36 0.28
pidmap_lock: 264 2 464.32 842.58 1306.90 653.45 15301 24012 0.00 3509.12 9530.52 0.40
input_pool.lock: 293 1 79.99 79.99 79.99 79.99 30259 42020 0.00 142.25 1488.55 0.04
&base->lock/1: 1 1 133.91 133.91 133.91 133.91 2 28 0.00 246.23 684.23 24.44
&mapping->i_mmap_rwsem: 619 1 20.89 20.89 20.89 20.89 28738 72030 0.00 6122.40 9692.90 0.13맨 위 &type->i_mutex_dir_key가 우리가 노린 디렉터리 아이노드 락이다. 20번 경합했고 평균 1,892µs를 기다렸는데, 보유 시간 평균은 11µs다. 잡고 있는 시간은 짧은데 기다리는 시간이 170배라는 것이 전형적인 경합의 모습이다.
경합 지점 읽기
각 클래스 아래에는 구분선과 함께 경합 지점이 붙는다. 첫 블록이 경합을 유발한 위치, 두 번째 블록이 그때 락을 쥐고 있던 위치다.
&type->i_mutex_dir_key#4/1: 991 20 35.95 8050.59 37845.05 1892.25 ...
--------------------------
&type->i_mutex_dir_key#4/1 523 [<(____ptrval____)>] filename_create+0xb9/0x160
&type->i_mutex_dir_key#4/1 470 [<(____ptrval____)>] filename_rmdir+0x18a/0x230
--------------------------
&type->i_mutex_dir_key#4/1 542 [<(____ptrval____)>] filename_create+0xb9/0x160
&type->i_mutex_dir_key#4/1 451 [<(____ptrval____)>] filename_rmdir+0x18a/0x230filename_create()와 filename_rmdir() — 정확히 mkdir과 rmdir 시스템 콜이 디렉터리 락을 잡는 지점이다. 워크로드를 모르는 상태에서 이 출력만 봐도 “같은 디렉터리에 생성/삭제가 몰리고 있다”를 짚어낼 수 있다.
같은 실행에서 두 번째로 눈에 띈 tasklist_lock의 경합 지점은 성격이 다르다.
tasklist_lock-W: 2367 5 ...
tasklist_lock-R: 1985 15 ...
---------------
tasklist_lock 894 [<(____ptrval____)>] do_exit+0x31f/0xb90
tasklist_lock 2021 [<(____ptrval____)>] __do_wait+0x4b/0x250
tasklist_lock 704 [<(____ptrval____)>] release_task+0xca/0x5b0
tasklist_lock 876 [<(____ptrval____)>] copy_process+0x1b6a/0x23a0클래스 이름 뒤의 -R/-W는 읽기/쓰기 획득을 따로 센 것이고, 호출 지점은 프로세스 생성·종료 경로다. 쉘 루프가 mkdir/rmdir마다 프로세스를 만들고 거두느라 생긴 부수 효과이지, 측정하려던 대상이 아니다. 워크로드가 만들어내는 이런 배경 잡음을 구분하는 것이 출력을 읽는 요령이다.
주의사항
- 프로덕션 커널에 켜지 말 것.
LOCK_STAT은LOCKDEP·DEBUG_SPINLOCK·DEBUG_MUTEXES를 강제로 함께 켜므로, 모든 락 연산에 훅과 검증이 붙는다. 성능 측정용 별도 커널에서만 쓰고, 여기서 얻은 절대 수치를 그대로 운영 환경 값으로 인용하지 않는다. - 경합 지점의 주소가
[<(____ptrval____)>]로 가려져 나온다.kptr_restrict때문인데, 심볼 이름과 오프셋은 그대로 보이므로 분석에는 지장이 없다. 주소가 꼭 필요하면sysctl -w kernel.kptr_restrict=0으로 풀 수 있다. - 통계는 락 인스턴스가 아니라 락 클래스 단위로 합산된다. 같은 코드에서 만들어진 서로 다른 디렉터리 아이노드 락은 한 줄로 합쳐지므로, “어떤 파일/디렉터리가 문제인가”까지는 알려주지 않는다. 그 단계는 perf lock이나 ftrace로 좁혀야 한다.
- 측정을 QEMU 소프트웨어 에뮬레이션(TCG)에서 돌리면 시간 관련 수치가 왜곡된다. 위 실행에서도 RCU stall 경고가 4번 찍혔고,
&rq->__lock의 최대 대기 시간이 10초를 넘게 잡힌다 — 실제 커널 동작이 아니라 에뮬레이션이 멈춘 구간이다. 경합의 상대적 순위와 경합 지점을 보는 용도로만 쓰고, 절대 시간은 실제 하드웨어에서 다시 재야 한다. - 배포판 커널에는
CONFIG_LOCK_STAT이 없다. Ubuntu 24.04의6.8.0-137-generic에도/proc/lock_stat이 존재하지 않아, 이 글의 측정은 전부 직접 빌드한 커널에서 진행했다. 커널을 새로 빌드할 수 없는 환경이라면 perf lock 쪽이 현실적인 대안이다.
마무리
lockstat은 켜는 비용이 큰 대신, “어느 락이 전체적으로 가장 많이 기다리게 만들고 있고 그 원인이 되는 코드 위치가 어디인지”를 한 화면에서 보여준다. 워크로드를 재현할 수 있는 개발·검증 커널에 켜두고, 대기 시간 대비 보유 시간 비율과 경합 지점 두 가지를 먼저 보는 것으로 대부분의 분석을 시작할 수 있다.