Improving Log File Sync times with Exadata Smart Flash Logs

The Smart Flash Log feature of Exadata provides a high performance temporary store for redo log writes. When enabled, the log writes are written to both disk and flash at the same time, and the first one to return an acknowledgment wins.

The Requirements for Smart Flash Log as follows:
Storage Server Version 11.2.2.4.0 or greater
Database Version 11.2.0.2 BP 11 or greater

I’ve been working with a client that has an application that has a high frequency of commits running on an X2-2 1/2 Rack that also generates around 600G of redo per day. The MOS note, Troubleshooting: “log file sync” Waits [ID 1376916.1], gives a formula to calculating the frequency of commits:

In the AWR or Statspack report, if the average user calls per commit/rollback calculated as “user calls/(user commits+user rollbacks)” is less than 30, then commits are happening too frequently.

With this particular client, this number turns out to be 13. Looking at the wait events from the AWR reports show high times for both log file sync and log file parallel writes.

Here is a graph of the log file sync and log file parallel write times before and after applying the Exadata bundle patch to an X2-2 ½ Rack this past weekend which enabled the flashlog feature. The drop shown in the graph is of course when the Bundle Patch was installed.

flashlog_and_lfs

Now, lets take a look at the performance metrics from the cells. It shows the amount of redo writes made to both disk and flash as well as the number of outliers prevented. Below the spreadsheet is the certain metrics from output from the cells. Around 10.5% of redo writes are going to flash and the number of redo write outliers prevented.

flashlog_redo_writes

Also worth mentioning is the FL_EFFICIENCY_PERCENTAGE% metrics listed below, all at 100% which is telling us that no redo writes have occurred that have taken over 0.5 seconds.

# dcli -g cell_group -l root "cellcli -e list metriccurrent where objectType=\'FLASHLOG\'"

exadcel01: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel01: FL_BY_KEEP                            FLASHLOG        0
exadcel01: FL_DISK_FIRST                         FLASHLOG        58,255,655 IO requests
exadcel01: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel01: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel01: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel01: FL_FLASH_FIRST                        FLASHLOG        6,275,774 IO requests
exadcel01: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel01: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel01: FL_IO_DB_BY_W                         FLASHLOG        537,635 MB
exadcel01: FL_IO_DB_BY_W_SEC                     FLASHLOG        5.191 MB/sec
exadcel01: FL_IO_FL_BY_W                         FLASHLOG        677,543 MB
exadcel01: FL_IO_FL_BY_W_SEC                     FLASHLOG        7.189 MB/sec
exadcel01: FL_IO_W                               FLASHLOG        64,531,429 IO requests
exadcel01: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel01: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel01: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel01: FL_PREVENTED_OUTLIERS                 FLASHLOG        163,136 IO requests
exadcel02: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel02: FL_BY_KEEP                            FLASHLOG        0
exadcel02: FL_DISK_FIRST                         FLASHLOG        53,770,032 IO requests
exadcel02: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel02: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel02: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel02: FL_FLASH_FIRST                        FLASHLOG        5,612,794 IO requests
exadcel02: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel02: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel02: FL_IO_DB_BY_W                         FLASHLOG        493,224 MB
exadcel02: FL_IO_DB_BY_W_SEC                     FLASHLOG        4.562 MB/sec
exadcel02: FL_IO_FL_BY_W                         FLASHLOG        621,982 MB
exadcel02: FL_IO_FL_BY_W_SEC                     FLASHLOG        6.283 MB/sec
exadcel02: FL_IO_W                               FLASHLOG        59,382,826 IO requests
exadcel02: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel02: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel02: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel02: FL_PREVENTED_OUTLIERS                 FLASHLOG        173,809 IO requests
exadcel03: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel03: FL_BY_KEEP                            FLASHLOG        0
exadcel03: FL_DISK_FIRST                         FLASHLOG        57,699,713 IO requests
exadcel03: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel03: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel03: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel03: FL_FLASH_FIRST                        FLASHLOG        6,605,007 IO requests
exadcel03: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel03: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel03: FL_IO_DB_BY_W                         FLASHLOG        535,277 MB
exadcel03: FL_IO_DB_BY_W_SEC                     FLASHLOG        5.676 MB/sec
exadcel03: FL_IO_FL_BY_W                         FLASHLOG        674,600 MB
exadcel03: FL_IO_FL_BY_W_SEC                     FLASHLOG        7.894 MB/sec
exadcel03: FL_IO_W                               FLASHLOG        64,304,720 IO requests
exadcel03: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel03: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel03: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel03: FL_PREVENTED_OUTLIERS                 FLASHLOG        282,466 IO requests
exadcel04: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel04: FL_BY_KEEP                            FLASHLOG        0
exadcel04: FL_DISK_FIRST                         FLASHLOG        48,862,092 IO requests
exadcel04: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel04: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel04: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel04: FL_FLASH_FIRST                        FLASHLOG        4,944,046 IO requests
exadcel04: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel04: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel04: FL_IO_DB_BY_W                         FLASHLOG        450,441 MB
exadcel04: FL_IO_DB_BY_W_SEC                     FLASHLOG        4.516 MB/sec
exadcel04: FL_IO_FL_BY_W                         FLASHLOG        566,957 MB
exadcel04: FL_IO_FL_BY_W_SEC                     FLASHLOG        6.287 MB/sec
exadcel04: FL_IO_W                               FLASHLOG        53,806,149 IO requests
exadcel04: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel04: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel04: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel04: FL_PREVENTED_OUTLIERS                 FLASHLOG        156,286 IO requests
exadcel05: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel05: FL_BY_KEEP                            FLASHLOG        0
exadcel05: FL_DISK_FIRST                         FLASHLOG        23,384,160 IO requests
exadcel05: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel05: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel05: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel05: FL_FLASH_FIRST                        FLASHLOG        2,313,231 IO requests
exadcel05: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel05: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel05: FL_IO_DB_BY_W                         FLASHLOG        192,781 MB
exadcel05: FL_IO_DB_BY_W_SEC                     FLASHLOG        6.347 MB/sec
exadcel05: FL_IO_FL_BY_W                         FLASHLOG        249,018 MB
exadcel05: FL_IO_FL_BY_W_SEC                     FLASHLOG        8.762 MB/sec
exadcel05: FL_IO_W                               FLASHLOG        25,697,391 IO requests
exadcel05: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel05: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel05: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel05: FL_PREVENTED_OUTLIERS                 FLASHLOG        38,088 IO requests
exadcel06: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel06: FL_BY_KEEP                            FLASHLOG        0
exadcel06: FL_DISK_FIRST                         FLASHLOG        58,983,319 IO requests
exadcel06: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel06: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel06: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel06: FL_FLASH_FIRST                        FLASHLOG        6,125,856 IO requests
exadcel06: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel06: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel06: FL_IO_DB_BY_W                         FLASHLOG        541,559 MB
exadcel06: FL_IO_DB_BY_W_SEC                     FLASHLOG        5.832 MB/sec
exadcel06: FL_IO_FL_BY_W                         FLASHLOG        682,942 MB
exadcel06: FL_IO_FL_BY_W_SEC                     FLASHLOG        8.171 MB/sec
exadcel06: FL_IO_W                               FLASHLOG        65,109,175 IO requests
exadcel06: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel06: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel06: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel06: FL_PREVENTED_OUTLIERS                 FLASHLOG        192,679 IO requests
exadcel07: FL_ACTUAL_OUTLIERS                    FLASHLOG        0 IO requests
exadcel07: FL_BY_KEEP                            FLASHLOG        0
exadcel07: FL_DISK_FIRST                         FLASHLOG        49,116,562 IO requests
exadcel07: FL_DISK_IO_ERRS                       FLASHLOG        0 IO requests
exadcel07: FL_EFFICIENCY_PERCENTAGE              FLASHLOG        100 %
exadcel07: FL_EFFICIENCY_PERCENTAGE_HOUR         FLASHLOG        100 %
exadcel07: FL_FLASH_FIRST                        FLASHLOG        4,924,721 IO requests
exadcel07: FL_FLASH_IO_ERRS                      FLASHLOG        0 IO requests
exadcel07: FL_FLASH_ONLY_OUTLIERS                FLASHLOG        0 IO requests
exadcel07: FL_IO_DB_BY_W                         FLASHLOG        450,464 MB
exadcel07: FL_IO_DB_BY_W_SEC                     FLASHLOG        4.574 MB/sec
exadcel07: FL_IO_FL_BY_W                         FLASHLOG        567,645 MB
exadcel07: FL_IO_FL_BY_W_SEC                     FLASHLOG        6.334 MB/sec
exadcel07: FL_IO_W                               FLASHLOG        54,041,283 IO requests
exadcel07: FL_IO_W_SKIP_BUSY                     FLASHLOG        0 IO requests
exadcel07: FL_IO_W_SKIP_BUSY_MIN                 FLASHLOG        0.0 IO/sec
exadcel07: FL_IO_W_SKIP_LARGE                    FLASHLOG        0 IO requests
exadcel07: FL_PREVENTED_OUTLIERS                 FLASHLOG        258,842 IO requests

Your mileage may will vary with the use of flash logs as I have seen some posts that don’t see a performance gain after enabling the flash logs, but it definitely helped in this case on a heavy write OLTP system.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s