{"id":"IL-0450","org":"Toss Securities","date":"2026-10-19","docs":[],"title":{"en":"Oracle RAC commits behind order APIs kept waiting over 0.1 s on log file sync while average host CPU had headroom","ko":"주문과 체결 API 뒤의 Oracle RAC 에서 커밋이 log file sync 대기로 0.1초 넘게 밀리는 일이 반복됐다"},"domain":["database"],"impact":{"scope":"Commits on the Oracle RAC database behind the order and execution APIs repeatedly waited over 0.1 s on log file sync, delaying API responses","users":"unknown","region":"unknown"},"review":{"written_by":"session","reviewed_at":null,"reviewed_by":null},"lessons":{"en":"Averages hide a bottleneck on a single core: the host CPU can be mostly idle while one core is full, so for intermittent delays it is worth checking with pidstat -t -p <pid> 1 which CPU a process runs on. Two reads of /proc/interrupts at a fixed interval show which device's interrupts land on which cores. On multi-socket servers, NIC and HBA ports are tied to a NUMA node, so slot placement should spread them over sockets, and Active-Standby bonding, while a redundancy setting, also puts all normal traffic and interrupts on one port; for critical paths Active-Active with ports on different sockets is worth considering. irqbalance is not always an answer, because the hardware and driver may not allow redistribution in software. No single layer was faulty; the problem was the combination of NIC slot, bonding mode and the core LGWR was scheduled on.","ko":"평균 지표만 보면 코어 하나에 걸린 병목을 놓친다. 호스트 CPU 가 80% 비어 있어도 어떤 코어는 쉴 틈이 없을 수 있다. 지연이 간헐적으로 나면 pidstat -t -p <pid> 1 로 그 프로세스가 어느 CPU 에서 도는지까지 본다. 장치별 인터럽트가 어느 코어에 몰리는지는 /proc/interrupts 를 일정한 간격으로 두 번 읽어 그 차이를 구하면 바로 드러난다.\n\n슬롯 배치도 성능 설계의 일부다. 다중 소켓 서버에서 NIC 와 HBA 포트는 특정 NUMA 노드에 연결되므로, 장비를 도입하거나 증설할 때는 소켓이 고르게 나뉘도록 꽂을 슬롯을 고른다. Active-Standby 본딩은 이중화를 해 주지만, 평소에는 트래픽과 인터럽트를 포트 하나에 모두 싣는다. 핵심 트래픽이 지나는 경로에는 Active-Active 구성과 소켓을 나눈 장착을 함께 검토한다. irqbalance 는 장비와 드라이버에 따라 인터럽트를 다시 나누지 못할 수 있으므로, 먼저 하드웨어와 드라이버의 제약을 확인한다."},"related":[],"sources":[{"url":"https://toss.tech/article/nic-interrupt-bottleneck","kind":"blog","archived":null}],"summary":{"en":"The database is a two-node Oracle RAC on servers with 4 CPU sockets of 8 physical cores each, 32 cores in total, shown as 64 logical CPUs with hyper-threading. Each socket is its own NUMA node, and each NIC port is physically connected to one socket, so the slot a NIC sits in decides which socket handles its interrupts. The two interconnect NICs were bonded in Active-Standby mode, so in normal operation all interconnect traffic, and all its interrupts, went through the active port and the one socket it was attached to. NIC interrupts are handled before ordinary processes: when a packet from the other node arrived while LGWR ran on one of those cores, the kernel paused LGWR to handle the interrupt on the same core, the redo write was delayed, and every session waiting for its commit waited too. Each stall was very short, but in busy periods they repeated until commit waits became visibly long, even though the host as a whole had idle CPU.\n\nThe team moved the two interconnect NICs into slots connected to different sockets and switched the bonding to Active-Active so both ports carry traffic, which spreads the interrupts over two sockets without any setting to remember at startup. In the same peak period afterwards, the physical cores handling more than 1,000 interrupts per second rose from 8 to 15 (16 to 31 logical CPUs) and the Gini coefficient of interrupt concentration fell from 0.80 to 0.67. On another RAC with the same change, on a day with 28% more concurrent users, average CPU in the first 10 minutes after market open fell from 36.6% to 17.4% and the 10-minute maximum from 42.5% to 21.9%. On the original server, kernel CPU (%system) in the peak 15 minutes fell from 7.77% to 5.89% on a day with 33% higher load, and 8 of the 9 SQL statements common to the AWR reports before and after ran faster per execution, the six main business statements by 10.5% to 30.8%. The change was then applied to every Oracle DB server in operation, and the log file sync waits of 0.1 s or more mostly improved.","ko":"토스증권의 주문과 체결 API 뒤에는 2노드 Oracle RAC 가 있다. 어느 날부터 이 DB 에서 log file sync 대기가 0.1초 넘게 이어지는 일이 반복됐다. Oracle 의 커밋은 LGWR 라는 백그라운드 프로세스가 리두 로그를 디스크에 기록한 뒤에야 끝나므로, LGWR 가 밀리면 그사이 커밋한 세션이 모두 기다리고 API 응답도 늦어졌다. 팀은 스토리지, OS, 네트워크, 애플리케이션, Oracle 을 하나씩 살폈지만 평균 지표에서는 이상을 찾지 못했다.\n\npidstat 으로 추적하자 지연은 LGWR 가 28번 CPU 에서 실행될 때만 생겼다. 이 서버는 CPU 소켓 4개에 소켓당 물리 코어 8개이고 하이퍼스레딩으로 논리 CPU 64개가 보이며, 소켓마다 NUMA 노드 하나를 이룬다. NIC 포트는 꽂힌 슬롯에 따라 특정 소켓 하나에 연결된다. RAC 인터커넥트용 NIC 2장은 Active-Standby 본딩으로 묶여 있었고, 평소에는 활성 포트 하나만 트래픽을 받았다. 인터커넥트는 두 노드가 캐시 블록을 주고받는 경로로, 클러스터에서 가장 바쁘다. 이 경로의 인터럽트가 모두 소켓 하나의 코어 8개에 몰렸다. NIC 인터럽트는 일반 프로세스보다 먼저 처리된다. 그래서 LGWR 가 이 코어에서 돌던 중에 패킷이 도착하면 커널이 LGWR 를 멈추고 인터럽트부터 처리했고, 그만큼 리두 로그 기록이 늦어졌다. 한 번 밀리는 시간은 아주 짧았지만 트래픽이 몰리는 구간에는 이 일이 계속 반복돼 커밋 대기가 눈에 띄게 길어졌다.\n\nirqbalance 는 NIC 큐와 CPU 의 매핑 제약 때문에 이 장비에 적용되지 않았다. taskset 으로 LGWR 를 고정하는 방법은 기동할 때마다 손으로 설정해야 해서 택하지 않았다. 대신 팀은 인터커넥트 NIC 2장을 각각 다른 소켓에 연결된 슬롯에 다시 꽂고, 본딩을 Active-Active 로 바꿨다. 같은 피크 시간대에 초당 1,000건 넘게 인터럽트를 처리하는 물리 코어가 8개에서 15개로 늘었고, 인터럽트가 몇몇 코어에 얼마나 몰렸는지를 나타내는 Gini 계수는 0.80에서 0.67로 내려갔다. 처음에 문제가 된 0.1초 이상의 log file sync 대기도 대부분 좋아졌다. 같은 조치를 한 다른 RAC 에서는 동시접속자가 28% 많은 날에도 개장 후 첫 10분 평균 CPU 사용률이 36.6%에서 17.4%로 내려갔다. 팀은 그 뒤 운영 중인 Oracle DB 서버 전체에 같은 조치를 적용했다."},"trigger":null,"severity":"unknown","symptoms":["high-latency"],"timeline":{"detected_after":null,"resolved_after":null},"date_kind":"published","detection":{"en":"The DBA team saw log file sync waits of more than 0.1 s recurring from some day on, while average metrics on every layer looked normal.","ko":"DBA 팀이 Oracle 의 log file sync 대기 이벤트에서 커밋이 0.1초 넘게 기다리는 일이 되풀이되는 것을 보고 알아챘다."},"components":["database","irq-affinity"],"root_cause":"capacity","remediation":[{"text":{"en":"Moved the two RAC interconnect NICs into slots attached to different CPU sockets and changed their bonding from Active-Standby to Active-Active","ko":"인터커넥트 NIC 2장을 각각 다른 CPU 소켓에 연결된 슬롯으로 옮겨 꽂았다. 본딩도 Active-Standby 에서 Active-Active 로 바꿔 평소에도 두 포트가 함께 트래픽을 받게 했다."}},{"text":{"en":"Applied the same change to every Oracle DB server in operation","ko":"운영 중인 Oracle DB 서버 전체로 같은 조치를 넓혔다."}}],"action_items":[],"contributing":["monitoring-blind-spot"],"recurrence_of":null,"symptoms_text":{"en":"Commits on the Oracle RAC database behind Toss Securities' order and execution APIs began to wait more than 0.1 s on the log file sync wait event, again and again, and API responses were delayed by the same amount. The DBA team checked storage, the OS, the network, the application and Oracle in turn, and every average metric was in the normal range; the host CPU also had headroom.\n\nlog file sync is the time a committing session waits until the background process LGWR (log writer) has written the redo log to disk. Every commit of an instance goes through LGWR, so even a short stall of LGWR makes every session that commits in the meantime wait with it. During regular trading hours, when orders pile up, even short delays mattered.\n\nBecause the delay was intermittent, the team suspected that averages were hiding it and traced LGWR in finer detail. Recording with pidstat which CPU LGWR ran on showed a pattern: the delay appeared only when LGWR ran on CPU 28. Reading /proc/interrupts twice, 30 seconds apart, showed that NIC interrupts were handled by only 8 of the 32 physical cores (16 of 64 logical CPUs), exactly one CPU socket, and CPU 28 was one of the cores dedicated to handling those interrupts.\n\nThe team first tried to spread the interrupts with irqbalance, but on this machine the setting did not take effect because of constraints on how NIC queues map to CPUs, and the interrupts stayed on the same cores. Pinning LGWR to a CPU of another socket with taskset was rejected because it would have to be set by hand at every Oracle start and could easily be missed.","ko":"주문과 체결을 처리하는 API 뒤의 Oracle RAC 에서 커밋 대기가 0.1초 넘게 이어지는 일이 반복해서 나타났다. 커밋이 밀리면 그 커밋을 기다리던 세션이 모두 함께 멈췄고 API 응답도 그만큼 늦어졌다.\n\n지연은 Oracle 의 log file sync 대기 이벤트에 잡혔다. log file sync 는 세션이 LGWR 가 리두 로그를 디스크에 다 쓸 때까지 기다리는 시간이다. 인스턴스의 커밋 기록은 모두 LGWR 한 프로세스를 거치므로, LGWR 가 잠깐만 밀려도 그사이 커밋한 세션이 전부 기다렸다.\n\n팀은 스토리지부터 OS, 네트워크, 애플리케이션, Oracle 까지 하나씩 살폈다. 평균 지표는 어디서나 정상 범위였고 호스트 CPU 도 남아 있었다. 팀은 지연이 간헐적이라 평균에 묻혔을 수 있다고 보고 LGWR 프로세스를 더 잘게 들여다봤다.\n\npidstat 으로 LGWR 가 실행되는 CPU 를 기록하자 지연은 LGWR 가 28번 CPU 에서 실행될 때만 생겼다. /proc/interrupts 를 30초 간격으로 두 번 읽어 차이를 보니 NIC 인터럽트가 물리 코어 32개 중 8개, 논리 CPU 로는 64개 중 16개에만 몰려 있었다. 그 물리 코어 8개는 정확히 CPU 소켓 하나 분량이었고, 28번 CPU 도 인터럽트를 전담하던 코어 중 하나였다.\n\n팀은 먼저 irqbalance 로 인터럽트를 다시 나누려 했다. 하지만 이 장비에서는 NIC 큐와 CPU 의 매핑 제약 때문에 설정이 적용되지 않았고, 인터럽트는 계속 같은 코어에 몰렸다. taskset 으로 LGWR 를 다른 소켓의 CPU 에 고정하는 방법도 검토했다. 그러나 Oracle 을 기동할 때마다 손으로 설정해야 해서 운영 중에 빠뜨리기 쉽다고 보고 쓰지 않았다."},"updated_at":"2026-11-14T12:34:09.883168Z","url":"https://benchlet.com/incidentlib/app/cases/IL-0450","org_slug":"toss-securities"}