AWR—"log file sync" Wait Event Analysis

There are some DB wait events could be caused by poor storage performance in Oracle.  For example,

• db File Sequential Read
• db File Scattered Read” wait events
• Direct Path Read
• Direct Path Read/Write temp
• Free Buffer Wait

In this article, I will discuss the log file sync wait event in Oracle AWR reports, which in many cases is caused by poor storage performance.

Top 10 Foreground Events by Total Wait Time

Event	Waits	Total Wait Time (sec)	Wait Avg(ms)	% DB time	Wait Class
DB CPU		2590.9		96.6
SQL*Net break/reset to client	5,864,510	546.4	0	20.4	Application
log file sync	19,575	25.5	1	1.0	Commit
SQL*Net message to client	15,493,939	10	0	.4	Network
library cache: mutex X	8,042	.6	0	.0	Concurrency
db file sequential read	93	.5	5	.0	User I/O
direct path read	158	.3	2	.0	User I/O
Disk file operations I/O	89	.1	1	.0	User I/O
SQL*Net more data to client	945	.1	0	.0	Network
cursor: pin S	39	.1	1	.0	Concurrency

Log File Sync

An Oracle user session issuing a commit command must wait until the LGWR (Log Writer) process writes the log entries associated with the user transaction to the log file on the disk. Oracle must commit the transaction’s entries to disk (because it is a persistent layer) before acknowledging the transaction commit. The log file sync wait event represents the time the session is waiting for the log buffers to be written to disk.

Sometimes you can find "log file sync" wait event appears on the top list of an AWR report:

Top 10 Foreground Events by Total Wait Time

What does it mean if log file sync is shown on the list?^[1]

• Is this noticeably slowing down all commits?
• Disk throughput is only one aspect that affects LGWR. It consumes CPU while executing too. 
•  If you've maxed out your CPU capacity processing "business transactions", then it will be starved for resource. This can lead to you seeing a lot of "log file sync" waits. 
• If your datafiles are on the same disks as the redo logs, then DBWR will also be contending for the same disk. 
• Is it just the top wait event on your system? 
• Remember that there's always something that has to be "top". 

How to Reduce "log file sync" Wait Time

When a user commits or rolls back data, the LGWR flushes the session's redo from the log buffer to the redo logs. The log file sync process must wait for this to successfully complete.

If log file sync is a problem (e.g., avg wait > 2 ms), try the following solutions based on its causes:^[1-4]

• Slow disk I/O
• Reduce contention on existing disks
• Put log files on faster disks and/or increasing the log_buffer size above 10 megabytes
• Put alternate redo logs on different disks to minimize the effect of archive processes (log files switches)
• LGWR is not getting enough CPU
• If the vmstat runqueue column is greater than cpu_count, then the instance is CPU-bound and this can manifest itself in high log file sync waits. The solution is to 
• Tune SQL (to reduce CPU overhead)
• Add processors
• 'Nice' the dispatching priority of the LGWR process
• High COMMIT activity
• Review application design, use NOLOGGING operations where appropriate, and reduce the frequency of COMMIT statements in the application
• LGWR is paged out
• Check the server for RAM swapping, and add RAM if the instance processes are getting paged-out.

References

1. Log file sync wait (Ask TOM)
2. Log file sync wait
3. Oracle Log File Sync Wait Event
4. Expert Consolidation in Oracle Database 12c
5. AWR Wait Events: Free Buffer Waits vs. Buffer Busy Waits (Xml and More)

Cloning: Listener won't start after cloning

This article is a companion article to our previous cloning series:

• Simplify Cloning by Using Hosts File
• Cloning Issue—IPv4 vs. IPv6 
• ORA-03113: end-of-file on communication channel
• Cloning Issue—What If Host Name(s) Are Stored in the Database
• ORA-01031: insufficient privileges
• Using rsync to Clone Local and Remote Systems
• ORA-00313: open failed for members of log group 1 of thread 1 
• Simplify Cloning by Using Hosts File

As pointed out in the previous articles, there are limitations and issues with cloning (either of an application or a database). This article describes one of the new issues.

TNS-00525: Insufficient privilege for operation

After cloning our OATS server to a new server, we have seen the following listener error when we restarted OATS' database on the new server:

### Starting tns listener ###

LSNRCTL for Linux: Version 11.2.0.2.0 - Production on 10-JUN-2014 19:48:43
Copyright (c) 1991, 2010, Oracle.  All rights reserved.
Starting /scratch/aime1/app/aime1/product/11.2.0/dbhome_1/bin/tnslsnr: please wait...
TNSLSNR for Linux: Version 11.2.0.2.0 - Production

System parameter file is /scratch/aime1/app/aime1/product/11.2.0/dbhome_1/network/admin/listener.ora

Log messages written to /scratch/aime1/app/aime1/diag/tnslsnr/myOatsServer/listener/alert/log.xml

Error listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=EXTPROC1521)))
TNS-12555: TNS:permission denied
 TNS-12560: TNS:protocol adapter error
  TNS-00525: Insufficient privilege for operation
   Linux Error: 1: Operation not permitted

The Solution

After trying tool such as truss or strace on Linux, it didn't help much.  Then, I have found articles [3,4] which have helped me solve the issue:

bash-3.2$cd /var/tmp

bash-3.2$ ls -la .oracle
total 12
drwxrwxrwt 2 root   root 4096 Mar 17 11:38 .
drwxrwxrwt 3 root   root 4096 Jun 10 18:28 ..
srwxrwxrwx 1 oracle lock    0 Mar 17 11:38 s#16150.1
srwxrwxrwx 1 oracle lock    0 Mar 17 11:38 s#16150.2
srwxrwxrwx 1 oracle lock    0 Feb 24 10:17 s#32488.1
srwxrwxrwx 1 oracle lock    0 Feb 24 10:17 s#32488.2
srwxrwxrwx 1 oracle lock    0 Mar 17 11:38 sEXTPROC1521

As shown above, our new server has an existing folder named .oracle under /var/tmp, which was owned by a different user (i.e. oracle).  After we have backed up our original .oracle folder, we have changed the owner of /var/tmp/.oracle to be aime1 and removed the files within it.  After restarting our listener, here are the new files generated in it:

.oracle:

total 0
srwxrwxrwx 1 aime1 svrtech 0 Jun 18 07:50 s#30309.1
srwxrwxrwx 1 aime1 svrtech 0 Jun 18 07:50 s#30309.2
srwxrwxrwx 1 aime1 svrtech 0 Jun 18 07:50 sEXTPROC1521

References

1. truss(1) equivalent in Linux ?
2. 5 simple ways to troubleshoot using Strace
3. Can't start listener for XE on Redhat Enterprise Linux 5.3 
4. Listener not starting with TNS-00525: Insufficient privilege for operation
5. Oracle Products: What Patching, Migration, and Upgrade Mean? (Xml and More)

AWR Wait Events: Free Buffer Waits vs. Buffer Busy Waits

To diagnose Oracle performance problems, you can use Automatic Workload Repository (AWR)^[1] to collect, process, and maintain performance statistics for problem detection. This data is both in memory and stored in the database. The gathered data can be displayed in both reports and views.

In this article, we will discuss the following topics:

• Top 5 Timed Foreground Events^[2]
• Free buffer Waits vs. Buffer Busy Waits^[3]

Top 5 Timed Foreground Events

The Top 5 Timed Foreground Events section is where you can usually spot the problem, by showing you why the sessions are “waiting.” Make sure to analyze the total waits and average waits (ms) separately, in order to determine if the waits are significant. 

For a given workload, this list of events should be relatively stable; you should investigate any significant variation. You will generally see DB CPU at the top of the list. However, CPU usage is not necessarily an indication of a healthy system, as the application may be CPU-bound. The most common wait events are:

• db file sequential read
• db file scattered read
• db file parallel read
• log file sync

In a nicely performing database, you should see CPU and I/O as the top wait events. If any wait events from the Concurrency wait class or Configuration wait class,^[7] investigate those waits further.  For example, in one of the AWR reports, we have found:

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
free buffer waits	1,336,444	20,880	16	55.33	Configuration
db file sequential read	11,443,820	12,942	1	34.30	User I/O
DB CPU		1,528		4.05
undo segment extension	5,031	547	109	1.45	Configuration
buffer busy waits	106	84	795	0.22	Concurrency

Free Buffer Waits

The Free Buffer Waits event indicates that your session is waiting for a buffer to become empty.  For instance, the database writer is copying the current contents to disc and your session has to wait for this to complete before you can empty the buffer and put something else in it.

Possible Causes and Solutions:

• DB_BUFFER_CACHE may need to be tuned^[4]
• If the cache hit ratio is low and your application is tuned to avoid performing full table scans, consider increasing the size of the buffer cache.
• If it is possible to allocate the extra memory required to the buffer cache without causing the system to page, then allocate extra memory.
• To increase the amount of memory allocated to the buffer cache, increase the value of the DB_CACHE_SIZE initialization parameter.
• If all your SQL is tuned, free buffer waits could also indicate that:
• Unselective SQL is causing data to flood the buffer cache with index blocks, leaving none for this particular statement that is waiting for the system to process. 
• This normally indicates that there is a substantial amount of DML (insert/update/delete) being done and that the Database Writer (DBWR) is not writing quickly enough; the buffer cache could be full of multiple versions of the same buffer, causing great inefficiency. 
• The solutions include, but not limited to:
• Avoid performing full table scans
• Accelerating incremental checkpointing, using more DBWR processes, increasing the size of buffer cache, or increasing the number of physical disks.
• Investigate if this is an I/O problem
• Look at the statspack file I/O Statistics.

Buffer Busy Waits

The Buffer Busy Waits event indicates that an Oracle session needs to access a block in the buffer cache,
but cannot because the buffer copy of the data block is locked. Buffer busy waits should not be greater than 1 percent.  This buffer busy wait condition can happen for either of the following reasons:

• The block is being read into the buffer by another session, so the waiting session must wait for the block read to complete. 
• Another session has the buffer block locked in a mode that is incompatible with the waiting session's request.

Possible Causes and Solutions:^[2,3,5]

• Check the Buffer Wait Statistics section (see next section) to find out if the wait is on:
• segment header
• Increase the freelist groups or increase the pctused to pctfree gap
• file header block
• If you are hitting file header block contention (Reason Code 13) on the temp files, increase the number of header blocks by adding more tempfiles.^[5]
• undo header
• Add rollback segments
• undo block
• Reduce the data density on the table driving this consistent read or increase the DB_CACHE_SIZE. 
• data block
• Move data to another block to avoid this hot block, increase the freelists on the table, or use Locally Managed Tablespaces (LMTs). 
• Use a smaller block size: fewer records fall within a single block in this case, so it's not as "hot." 
• index block
• Rebuild the index, partition the index, or use a reverse key index. 
• When a DML (insert/update/ delete) occurs, Oracle Database writes information into the block, including all users who are "interested" in the state of the block (Interested Transaction List, ITL). 
• To decrease waits in this area, you can:
• Increase the initrans, which will create the space in the block to allow multiple ITL slots. 
• Increase the pctfree on the table where this block exists (this writes the ITL information up to the number specified by maxtrans, when there are not enough slots built with the initrans that is specified).
• Other tunings
• Database writer (DBWR) contention tuning
• Implementing Automatic Segment Storage Management (ASSM, a.k.a bitmap freelists)

Buffer Wait Statistics

Here is the Buffer Wait Statistics section from our AWR snapshot:

• ordered by wait time desc, waits desc

Class	Waits	Total Wait Time (s)	Avg Time (ms)
undo header	827	752	909
file header block	45	40	896
data block	11	0	7

SQL ordered by Elapsed Time

Finally, from the SQL Ordered by Elapsed Time section, it seems to indicate that a DML (i.e., delete) operation poorly performed.  This has given us another clue to investigate our performance issue.  From the SQL Id, you should be able to find out more details of the interested SQL in your AWR snapshot.

Elapsed Time (s)	CPU Time (s)	Executions	Elap per Exec (s)	% Total DB Time	SQL Id	SQL Module	SQL Text
35,931	1,457	1,000	35.93	95.22	83uuf84dqpbaq		delete /*+ INDEX (a EQ$ATTR_VA...
35,925	1,479	0		95.20	6vyng4f5vktyb		DECLARE job BINARY_INTEGER := ...

References

1. Overview of the Automatic Workload Repository
2. AWR Top 5 Timed Events - Top 10
3. What is the difference between buffer busy waits and free buffer waits
4. Tuning the Database Buffer Cache
5. Resolving file header contention on tempfiles
6. Oracle® Database Performance Tuning Guide 10g Release 2 (10.2)
7. Classes of Wait Events
• Configuration: Waits caused by inadequate configuration of database or instance resources (for example, undersized log file sizes, shared pool size)
• Concurrency: Waits for internal database resources (for example, latches)
8. Oracle® Database Reference 10g Release 2 (10.2)
9. More on Interested Transaction Lists
10. Oracle automatic segment space management:  ASSM internal structures

Book Review: Managing Multimedia and Unstructured Data in the Oracle Database

There is a large amount of unstructured data in the real world. In 1998, Merrill Lynch cited a rule of thumb that somewhere around 80-90% of all potentially usable business information may originate in unstructured form^[1].

There is no doubt that we need to process this information to extract meaning and create structured data about the information.  One approach will be using Oracle Database to manage such data which includes multimedia (aka "rich media").  This book:

• Managing Multimedia and Unstructured Data in the Oracle Database

aims to help readers understand and manage unstructured data using Oracle Database.

Dealing with Unstructured Data

Unstructured Data refers to information that either does not have a pre-defined data model and/or does not fit well into relational tables^[1].

Relational data can be considered a subset of structured data.  Besides relational databases, structured data can also be stored in non-relational format such as in XML, inverted list databases^[2], or object databases^[4]. XML does not conform with formal structure of data models, but nonetheless it contains tags to separate  semantic elements and enforce hierarchies of records and fields within the data.  Therefore, one can consider XML as semi-structured.

It's possible to store unstructured data in a column of a relational table, which is structured.  The traditional approach has been to just treat it as a blob (binary large object), but with a greater understanding of the variety of unstructured data types (i.e., video, audio, photographs, documents, etc.) that exist, the need to manage them has grown.

Metadata

To manage unstructured data, metadata is crucial. It is the data that describes the unstructured data and gives meaning to it.   Metadata can be used for

• Searching (covered in Chapter 4, Searching the Multimedia Warehouse)
• Annotation
• Adding meaning to unstructured data objects
• Relating unstructured data objects (or adding structure)
• Matching data stored in relational databases

It is envisaged that in the future technology will improve to the point that algorithms will be able to identify objects and people in a video or photo, and understand sounds and complex speech in audio files. When that point is reached, the need for metadata may be reduced or limited to a smaller scope.

Oracle Database

In the past few years, with changes in database technology and improvements in disk performance and storage, it now makes business sense to use the Oracle database to store and manage all of an organization's unstructured data.

For a database management system to begin to correctly handle the unstructured data, it must have support for objects^[4].  The use of a database that can support objects makes it a lot easier to manage large volumes of digital objects. Though these objects can be stored in a file system, there are now advantages to having them stored inside the database.  In Oracle, both relational data and objects are supported.  After adding Online Analytical Processing (OLAP)^[5] and XML^[6], Oracle database grew from being relational to one supporting most structures.

Oracle multimedia uses blobs and new types, which can be accessed and used as required. In addition, it supports a variety of methods that simplify the act of loading and manipulating digital objects. This is covered in in Chapter 7, Techniques for Creating a Multimedia Database.

Most databases can enable unstructured data to be stored in them, but do not support the management, control, and manipulation of that data. Even though Oracle is a market leader in unstructured data management there are still a large number of major improvements needed.  This is covered in Chapter 9, Understanding the Limitations of Oracle Products.

Scalability

When working with multimedia and unstructured data, a row in the database can be 10 GB in size, which could be greater than an entire relational database.  Therefore, traditional tuning techniques might fail as the rules regarding them no longer make sense.

For example, in a multimedia warehouse (covered in Chapter 4), the concept of trying to achieve logical data consistency is not attempted, as it becomes apparent that the amount of data that is fuzzy forms the bulk of most of the digital objects.  So, novel solutions to tuning problems are needed.

In Oracle Multimedia, there are also built-in supports for scalability.  For example, the new 11G Securefile BLOBS using parallel techniques, that allows of loading of files much faster than using traditional BLOBS.

From the hardware front, technology also offers help.  With the recent introduction of a low-cost terabyte SATA disks, and with the use of low-cost SAN's, the ability to store a petabyte is within the reach of a number of organizations.

To handle large amount of unstructured data, issues seen and solutions provided by Oracle include:

• Hitting limits on the image size
• An Oracle BLOB can be unlimited in size
• Reaching internal structural limits within the database (max number of files that store data)
• Oracle's use of tablespaces allow a large number of multimedia files to be stored in it
• With the ability to control where a blob is stored, files can be split across multiple tablespaces and devices 
• Dealing with fragmentation 
• By using locally managed tablespaces, fragmentation is removed as a performance issue. 
• The efficient management of those images (for example, backup/recovery)
• Using partitioning on LOBS allows a very large number of multimedia files to be stored and efficiently managed
• Using RMAN, Oracle can be configured to back up large amounts of data

When dealing with Multimedia, one has to look at the different dimensions of scalability to best understand how the Oracle Database best handles it.  This includes managing the CPU, memory, disk I/O, and network bandwidth. All of the above are covered in Chap 8, Tuning.

References

1. Unstructured data (Wikipedia)
2. ADABAS (Wikipedia)
3. 3D Printing (Wikipedia)
4. Object Database (Wikipedia)
5. Oracle OLAP
6. Oracle XML DB
7. Managing Multimedia and Unstructured Data in the Oracle Database (Reviewed Book)