So Far So Good with Force Logging

I mentioned in my previous two posts that I had tried to figure out if it would be safe to turn on force logging on a production database that does a bunch of batch processing on the weekend: post1, post2. We know that many of the tables are set to NOLOGGING and some of the inserts have the append hint. We put in force logging on Friday and the heavy weekend processing ran fine last weekend.

I used an AWR report to check the top INSERT statements from the weekend and I only found one that was significantly slower. But the table it inserts into is set for LOGGING, it does not have an append hint, and the parallel degree is set to 1. So, it is a normal insert that was slower last weekend for some other reason. Here is the output of my sqlstatsumday.sql script for the slower insert:

Day        SQL_ID        PLAN_HASH_VALUE Executions Elapsed Average ms CPU Average ms IO Average ms Cluster Average ms Application Average ms Concurrency Average ms Average buffer gets Average disk reads Average rows processed
---------- ------------- --------------- ---------- ------------------ -------------- ------------- ------------------ ---------------------- ---------------------- ------------------- ------------------ ----------------------
2019-09-22 6mcqczrk3k5wm       472069319        129         36734.0024     20656.8462    462.098677                  0                      0             38.8160385          666208.285         1139.86923             486.323077
2019-09-29 6mcqczrk3k5wm       472069319        130         44951.6935     27021.6031    573.245664                  0                      0             21.8764885           879019.29         1273.52672             522.083969
2019-10-06 6mcqczrk3k5wm       472069319        130         9624.33742     7530.07634    264.929008                  0                      0             1.26370992          241467.023         678.458015             443.427481
2019-10-13 6mcqczrk3k5wm       472069319        130         55773.0864      41109.542    472.788031                  0                      0             17.5326031          1232828.64         932.083969             289.183206
2019-10-20 6mcqczrk3k5wm       472069319        130         89684.8089     59261.2977    621.276122                  0                      0             33.7963893          1803517.19         1242.61069             433.473282
2019-10-27 6mcqczrk3k5wm       472069319        130         197062.591     144222.595    561.707321                  0                      0             362.101267          10636602.9         1228.91603             629.839695

It averaged 197062 milliseconds last weekend but 89684 the previous one. The target table has always been set to LOGGING so FORCE LOGGING would not change anything with it.

One of the three INSERT statements that I expected to be slowed by FORCE LOGGING was faster this weekend than without FORCE LOGGING last weekend:

Day        SQL_ID        PLAN_HASH_VALUE Executions Elapsed Average ms CPU Average ms IO Average ms Cluster Average ms Application Average ms Concurrency Average ms Average buffer gets Average disk reads Average rows processed
---------- ------------- --------------- ---------- ------------------ -------------- ------------- ------------------ ---------------------- ---------------------- ------------------- ------------------ ----------------------
2019-09-22 0u0drxbt5qtqk       382840242          1         2610257.66         391635    926539.984                  0                      0              13718.453             5483472           745816.5                3689449
2019-09-29 0u0drxbt5qtqk       382840242          1         17127212.3        1507065    12885171.7                  0                      0             14888.4595            18070434          6793555.5             15028884.5
2019-10-06 0u0drxbt5qtqk       382840242          1         3531931.07         420150    2355139.38                  0                      0             12045.0115             5004273            1692754                5101998
2019-10-13 0u0drxbt5qtqk       382840242          1         1693415.59         180730    1250325.41                  0                      0               819.7725           2242638.5           737704.5                2142812
2019-10-20 0u0drxbt5qtqk       382840242          1         5672230.17         536115    3759795.33                  0                      0             10072.9125             6149731            2332038              2806037.5
2019-10-27 0u0drxbt5qtqk       382840242          1         2421533.59         272585    1748338.89                  0                      0               9390.821           3311219.5           958592.5              2794748.5

It ran 2421533 milliseconds this weekend and 5672230 the prior one. So clearly FORCE LOGGING did not have much effect on its overall run time.

It went so well this weekend that we decided to leave FORCE LOGGING in for now to see if it slows down the mid-week jobs and the web-based front end. I was confident on Friday, but I am even more confident now that NOLOGGING writes have minimal performance benefits on this system. But we will let it bake in for a while. Really, we might as well leave it in for good if only for the recovery benefits. Then when we configure GGS for the zero downtime upgrade it will already have been there for some time.

The lesson for me from this experience and the message of my last three posts is that NOLOGGING writes may have less benefits than you think, or your system may be doing less NOLOGGING writes than you think. That was true for me for this one database. It may be true for other systems that I expect to have a lot of NOLOGGING writes. Maybe someone reading this will find that they can safely use FORCE LOGGING on a database that they think does a lot of NOLOGGING writes, but which really does not need NOLOGGING for good performance.

Bobby