High log file sync in Oracle RAC: When Redo Storage Is Not the Real Problem

  When commit response time suddenly becomes poor, seeing log file sync near the top of an AWR report naturally sends a DBA toward redo I/O, ASM, and the underlying storage path.

That is the right place to start, but not always the right place to stop.

A foreground session waiting on log file sync is waiting for its commit to complete. The physical redo write is only one part of that path. If LGWR cannot get CPU quickly enough, the application can experience slow commits even while redo writes themselves remain fast.

The RAC case below is a good example of why Oracle wait events, operating-system scheduling, commit volume, and service placement need to be looked at together rather than independently.

The production symptom

The workload was running on a two-node Oracle Database 19c RAC cluster. During a busy period, the payment application started showing transaction response times roughly three to five seconds higher than normal.

There was no RAC instance eviction, ASM was not reporting a storage problem, and synchronous Data Guard transport latency had not increased. The initial evidence looked like this:

Observation	Finding
log file sync	38 ms average; 62% of DB time
log file parallel write	1.4 ms average
Commits/sec	Increased from 12K to 25K
ASM write latency	Below 2 ms
Node 1 CPU	18%
Node 2 CPU	95%; run queue 18–25 on 8 vCPUs
Service placement	Payment service runs only on node 2
Data Guard transport	No increase in synchronous transport waits

The tempting conclusion was that redo storage was slow because log file sync was dominating database time.

But 1.4 ms for log file parallel write and sub-2 ms ASM latency did not fit that theory. The bigger clue was elsewhere: node 2 was almost fully consumed while node 1 had plenty of CPU available.

The part of log file sync that is easy to miss

A commit is not simply a foreground session issuing a disk write. There is coordination between the foreground process and LGWR.

A simplified commit path looks like this:

Foreground session issues COMMIT
        |
        | (posts LGWR)
        ↓
LGWR gets scheduled
        |
        | (processes the commit request)
        ↓
LGWR writes redo
        |
        | (redo write completes)
        ↓
LGWR posts completion
        ↓
Foreground session continues

The foreground session measures the overall delay as log file sync. That can include the time needed to notify LGWR, LGWR scheduling delay, batching or queueing, the actual redo write, and the completion notification back to the foreground session.

log file parallel write is different. It is associated with the redo write operation seen by LGWR and is therefore a useful indicator when checking whether redo I/O itself is slow.

The two events are related, but they are not two copies of the same timer.

So when foreground commits are taking around 38 ms while LGWR redo writes are around 1.4 ms, there is roughly 36 ms of additional time that needs explaining. That difference does not automatically prove CPU starvation, but it is enough to stop treating storage as the only suspect.

In RAC, compare the instances before chasing database-wide averages

One of the first things I would do on RAC is separate the evidence by instance.

A database-wide average can easily hide an overloaded node. If instance 1 is healthy while instance 2 is struggling, looking only at cluster-level numbers makes the situation appear less severe than it really is.

SET LINES 220
COL event FORMAT A30

SELECT inst_id,
event,
total_waits,
ROUND(time_waited_micro / 1000000, 2) AS total_wait_s,
ROUND(time_waited_micro / NULLIF(total_waits, 0) / 1000, 2) AS avg_wait_ms FROM   gv$system_event WHERE  event IN ('log file sync', 'log file parallel write')
ORDER BY inst_id, event;

SELECT inst_id,
event,
wait_time_milli,
wait_count FROM   gv$event_histogram WHERE  event IN ('log file sync', 'log file parallel write')
ORDER BY inst_id, event, wait_time_milli;

There is one important point with GV$SYSTEM_EVENT: these values are cumulative since instance startup. For a short incident, the lifetime average can be misleading.

Take two snapshots around the problem period and work with the delta. If AWR usage is licensed in your environment, the corresponding AWR interval can also provide the incident-specific view.

I also like the event histogram here because averages can hide the tail. Two systems can both show an average commit latency of 10 ms while having very different distributions. One may consistently commit around 10 ms; another may have mostly fast commits mixed with a smaller number taking hundreds of milliseconds.

The commit rate change was another important clue

A high number of commits per second is not automatically a problem. Some payment, messaging, and event-driven applications naturally work with many small transactions.

What matters is whether the workload changed.

In this case the commit rate had moved from roughly 12,000 to 25,000 commits per second. That is large enough to ask what changed on the application side and whether the amount of redo increased at the same rate.

The following counters can be sampled twice, for example 60 seconds apart:

SELECT inst_id,
       name,
       value
FROM   gv$sysstat
WHERE  name IN ('user commits',
                'user rollbacks',
                'redo size',
                'redo writes')
ORDER BY inst_id, name;

Take the difference between the two samples and divide by the collection interval. That gives a much more useful short-term rate than looking at the raw cumulative counters.

I would also calculate redo bytes per commit. If commit frequency doubles while redo volume does not increase proportionally, the application may simply be creating many more small transactions.

That is capable of putting significant pressure on the commit path without saturating the redo device.

A common application pattern worth checking

One pattern worth discussing with the application team is a commit inside a tight processing loop:

-- Expensive when each row does not need to be
-- an independent durable transaction

FOR r IN source_rows LOOP UPDATE payment_stage SET    processed_flag = 'Y' WHERE  payment_id = r.payment_id;

COMMIT;
END LOOP;

The DBA should not blindly remove commits from application code. Transaction boundaries are part of application correctness and recovery behavior.

The useful DBA contribution is to show that commit frequency changed, quantify the database impact, and let the application owners determine whether every durability boundary is really required.

Find the service or module generating the pressure

The next question is not just, “Which SQL is expensive?”

Commit-heavy workloads are often made up of thousands of individually cheap calls. Looking only for a single SQL statement with high elapsed time may therefore miss the real pattern.

If ASH is available and your environment is appropriately licensed, grouping activity by instance, service, module, action, SQL ID, and wait event gives a much better picture.

SELECT ash.inst_id,
       NVL(svc.name, TO_CHAR(ash.service_hash)) AS service_name,
       NVL(ash.module, 'UNKNOWN') AS module,
       NVL(ash.action, 'UNKNOWN') AS action,
       ash.sql_id,
       ash.event,
       COUNT(*) AS samples
FROM   gv$active_session_history ash
       LEFT JOIN gv$active_services svc
         ON svc.inst_id = ash.inst_id
        AND svc.name_hash = ash.service_hash
WHERE  ash.sample_time >= SYSTIMESTAMP - INTERVAL '15' MINUTE
AND    (ash.event = 'log file sync'
        OR ash.session_state = 'ON CPU')
GROUP BY ash.inst_id,
         NVL(svc.name, TO_CHAR(ash.service_hash)),
         NVL(ash.module, 'UNKNOWN'),
         NVL(ash.action, 'UNKNOWN'),
         ash.sql_id,
         ash.event
ORDER BY samples DESC
FETCH FIRST 30 ROWS ONLY;

ASH is sampled activity, so I would not use it as a transaction counter. What it does very well is show where database activity accumulated during the incident.

Here the active samples were concentrated around the payment workload on instance 2. That lined up with the service configuration and the operating-system data.

If Diagnostic Pack usage is not licensed, the same investigation can still be built from repeated samples of views such as GV$SESSION, GV$SYSTEM_EVENT, and GV$SYSSTAT, together with application monitoring and OS statistics.

The operating system completed the picture

At this stage the Oracle evidence told us that the missing time was probably not in the physical redo write. The OS evidence was needed to understand where it was going.

Node 2 was around 95% CPU utilization. More importantly, the run queue was between 18 and 25 on a machine with only 8 vCPUs.

That tells a different story from “the redo disk is slow.” There were simply more runnable processes than the CPUs could schedule promptly.

Identify LGWR first

SET LINES 180
COL program FORMAT A45

SELECT inst_id,
spid,
program FROM   gv$process WHERE  program LIKE '%LGWR%'
ORDER BY inst_id, spid;

Once the LGWR operating-system PID is known, correlate it with node-level scheduling data from the same incident window.

# CPU utilisation, runnable processes and blocked processes
vmstat 1 60
sar -q 1 60

# Per-CPU utilisation, including iowait and steal

mpstat -P ALL 1 60

# Replace  with the SPID found in GV$PROCESS

pidstat -u -w -p  1 60

# Check process/thread state and CPU placement

ps -eLo pid,tid,psr,pcpu,stat,comm,args | grep -E 'ora_lgwr|PID'

The important correlation was that redo I/O remained fast while node 2 repeatedly showed CPU pressure and a long runnable queue. LGWR was not spending most of the missing time waiting for the redo device. It was competing with other runnable work for CPU.

On a virtual machine, I would extend the same check to CPU steal time, VM throttling, host oversubscription, and any cgroup or container CPU limits. A database process can appear CPU-starved inside the guest even when the root cause is outside Oracle.

Why I would still check Data Guard

Synchronous Data Guard transport can also sit directly in the commit path. If remote acknowledgement becomes slower, foreground commit latency may increase even when the local redo device is healthy.

For that reason, I would still compare synchronous redo transport waits, network behavior, standby health, and any recent protection-mode changes.

In this case those waits had not increased. That helped rule out the standby and WAN path and kept the investigation focused on the local RAC node.

The service placement made the imbalance worse

This was not only a CPU problem. It was also a workload placement problem.

Node 1 was using around 18% CPU while node 2 was close to saturation, yet the payment service was running only on instance 2.

That meant the most commit-sensitive workload in the cluster was concentrated on the node with the least CPU headroom.

During an incident, relocating the service may therefore be a practical recovery option if the other node genuinely has capacity and the application is designed to tolerate the move.

srvctl status service -db PAYDB -service PAY_SVC -verbose
srvctl config service -db PAYDB -service PAY_SVC

# Evaluate the relocation before executing it

srvctl relocate service -db PAYDB -service PAY_SVC 
-oldinst PAYDB2 -newinst PAYDB1 -eval -verbose

# Execute after application, capacity and change checks

srvctl relocate service -db PAYDB -service PAY_SVC 
-oldinst PAYDB2 -newinst PAYDB1 -drain_timeout 60 -verbose

I would not treat service relocation as a casual command to run whenever CPU becomes high. Check the target instance capacity, connection-pool behavior, drain requirements, and Application Continuity configuration where applicable.

Also remember that srvctl relocate service is a runtime relocation. If the preferred and available instance design is wrong, that policy still needs to be corrected separately.

What I would do during the incident

The immediate objective is to bring commit latency back under control. Application redesign can come later.

• Reduce or pause the newly increased commit-heavy workload if operationally possible.
• Identify other CPU consumers on node 2 and remove avoidable contention.
• Restore CPU capacity if the VM or host is constrained.
• Consider moving the affected RAC service to node 1 after validating capacity and service behavior.

The important point is that none of these actions requires pretending the redo disks are slow when the evidence says otherwise.

Two shortcuts I would avoid

A. Changing commit durability to hide the wait

Using something such as COMMIT_WRITE=NOWAIT may reduce the foreground waiting time, but it changes commit durability behavior.

That is not the same as fixing CPU starvation or excessive commit pressure. Making the response faster by changing the durability guarantee can introduce a much more serious problem than the original latency issue.

B. Immediately changing LGWR CPU priority or affinity

I would also avoid jumping directly into LGWR priority or CPU-affinity tuning without understanding the host design and vendor guidance.

Those changes may only shift CPU pressure to another process and can make the next incident more difficult to understand.

What needs to be fixed after the incident

Once the immediate pressure is removed, I would separate the permanent work into workload, placement, and monitoring.

1. Review why the commit frequency increased

The application team should understand why transaction frequency moved from roughly 12K to 25K commits per second and whether all those transaction boundaries are required.

The objective is not to make every transaction artificially large. It is to avoid unnecessary commit points that provide no business or recovery benefit.

2. Revisit RAC service placement

A critical service sitting entirely on a heavily loaded instance while another RAC node remains mostly idle deserves review.

Preferred instances, available instances, connection pools, failover policy, and actual runtime capacity all need to agree with each other.

Also remember that database workload is not the only consumer of CPU. Backup processes, security agents, monitoring software, host scans, and unrelated application jobs can all reduce the CPU available to Oracle background processes.

3. Monitor the complete commit path

For a commit-sensitive RAC workload, I would want the operational dashboard to correlate at least:

• log file sync latency and histogram distribution
• log file parallel write latency
• commits per second
• redo bytes per second and redo bytes per commit
• CPU utilization and run queue by RAC node
• CPU steal time or throttling on virtual infrastructure
• RAC service placement and session distribution
• synchronous Data Guard transport latency where applicable

Any one of these metrics viewed on its own can send the investigation in the wrong direction. Their relationship is what explains the commit path.

Takeaway

A high log file sync wait tells us that foreground sessions are spending too much time completing commits. It does not tell us, by itself, that the redo storage is slow.

If log file parallel write remains low and ASM write latency is healthy, look at the rest of the path. Compare RAC instances, measure the change in commit volume, identify which service is producing the activity, and check whether LGWR can actually get CPU when it needs it.

In this case the important combination was simple once the evidence was put together: commit volume had sharply increased, the payment service was concentrated on instance 2, and that node was already close to CPU saturation with a long run queue.

Redo writes were completing quickly. The delay was in getting the work scheduled quickly enough around them.

That distinction prevents a lot of wasted tuning effort. Faster disks would not have solved this incident. Looking across Oracle waits, RAC topology, workload behavior, and OS scheduling did.

Oracle references

• Oracle Database 19c Reference: V$EVENT_HISTOGRAM
• Oracle Database 19c Reference: V$ACTIVE_SESSION_HISTORY
• Oracle Database 19c: Server Control Utility Reference