{"id":6793,"date":"2016-01-10T19:29:21","date_gmt":"2016-01-10T18:29:21","guid":{"rendered":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/"},"modified":"2016-01-10T19:29:21","modified_gmt":"2016-01-10T18:29:21","slug":"log-file-sync-user-commits","status":"publish","type":"post","link":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/","title":{"rendered":"log file sync \/ user commits"},"content":{"rendered":"

By Franck Pachot<\/h2>\n

.
\nWhen presenting ‘Interpreting AWR Reports – Straight to the Goal’ at UKOUG TECH15 I had a very good question about the Statspack report I read which had log file sync much smaller than user commits. I realized that this needs a longer explanation, and that my slide is very misleading because I divided log file sync wait time per user commits, which probably make no sense here.
\n
\n\"CapturePreziAWR-Commit\"<\/a><\/p>\n

log file sync<\/h3>\n

‘log file sync’ occurs at commit time when your session waits that all redo protecting the transaction is written on disk. The idea is that when the end-user receives a ‘commit successful’ response, he expects that the changes are durable – as the D in ACID – even in case of instance crash. That means that the redo must be on a persistent storage.<\/p>\n

User commits<\/h3>\n

In my presentation about reading an AWR report I show how we must always match the event time with the end-user response time. And that was probably my idea when dividing ‘log file sync’ by ‘user commits’. But that was probably a bad idea here and I’ll change this slide for the next presentation (soon: http:\/\/oraclemidlands.com\/<\/a>) because it makes no sense.<\/p>\n

SQL commit<\/h3>\n

I’ll take simple examples to explain. In the first example I run 2000 insert + commit and chack the session statistics:<\/p>\n

\nSTAT\/EVENT                                              VALUE                   \n-------------------------------------------------- ----------                   \nSTAT user commits                                        2000                   \nSTAT user calls                                          8017                   \nSTAT redo size                                        1121052                   \nWAIT log file sync                                       2001                   \n<\/code><\/pre>\n
As you can see here, each commit (‘user commit’) increase the ‘log file sync’ event. It may be very quick if redo is already on disk but the wait event is always incremented.<\/p>\n
SQL commit write<\/h3>\n
Same with ‘commit write’ which uses the commit_logging and commit_wait parameters (the default here):<\/p>\n
\nSTAT\/EVENT                                              VALUE                   \n-------------------------------------------------- ----------                   \nSTAT user commits                                        2000                   \nSTAT redo size                                        1171124                   \nSTAT commit batch\/immediate requested                    2000                   \nSTAT commit immediate requested                          2000                   \nSTAT commit batch\/immediate performed                    2000                   \nSTAT commit immediate performed                          2000                   \nSTAT commit wait\/nowait requested                        2000                   \nSTAT commit wait requested                               2000                   \nSTAT commit wait\/nowait performed                        2000                   \nSTAT commit wait performed                               2000                   \nSTAT execute count                                       4128                   \nWAIT log file sync                                       2001                   \n<\/code><\/pre>\n
Same values here, but more detail. From the values we see that commit write IMMEDIATE WAIT was performed<\/p>\n
SQL commit write batch nowait<\/h3>\n
I’ll not show all combinations here. Here is BATCH (to optimize redo size to write) and NOWAIT:<\/p>\n
\nSTAT\/EVENT                                              VALUE                   \n-------------------------------------------------- ----------                   \nSTAT user commits                                        2000                   \nSTAT redo size                                        1034768                   \nSTAT commit batch\/immediate requested                    2000                   \nSTAT commit batch requested                              2000                   \nSTAT commit batch\/immediate performed                    2000                   \nSTAT commit batch performed                              2000                   \nSTAT commit wait\/nowait requested                        2000                   \nSTAT commit nowait requested                             2000                   \nSTAT commit wait\/nowait performed                        2000                   \nSTAT commit nowait performed                             2000                   \nWAIT log file sync                                          1                   \n<\/code><\/pre>\n
With NOWAIT, we don’t wait for log writer and we don’t have any ‘log file sync’. Which means that the response time of the commit is nearly immediate (only the time to update the transaction table). But of course, we may lose a commited transaction if log writer didn’t have time to write it before an instance crash.<\/p>\n
This is the case I have in my example, and this is the reason why ‘log file sync’ is lower than ‘user commits’;
\nActually the example was done with Swingbench<\/a> where transactions are done in a pl\/sql procedure.<\/p>\n
PL\/SQL loop with commit<\/h3>\n
Here I’m calling 100 times a PL\/SQL procedure that do 20 commits inside.<\/p>\n
\nSTAT\/EVENT                                              VALUE                   \n-------------------------------------------------- ----------                   \nSTAT user commits                                        2000                   \nSTAT redo size                                        1044088                   \nWAIT log file sync                                        101              \n<\/code><\/pre>\n
PL\/SQL default is different. It is doing something like NOWAIT BATCH implicitly. The idea is that you care that redo is persisted or not when it’s in the middle of a user call, because if it crashes, nobody has been notified that it is committed. Of course that may not be the right way if there are other users notified. We can go back to the SQL behavior by issuing ‘COMMIT WRITE’.<\/p>\n
When the PL\/SQL exits and there has been some commit done, an additional commit is done in WAIT mode this time, to be sure that all redo is persisted before returning to end-user.<\/p>\n
Conclusion<\/h3>\n
The ‘log file sync wait event’ is actually the one that measure the number of times the end-user has waited on commit. And I was wrong to divide it by ‘user commits’. I’m changing the slide to the following.
\n\"CapturePreziAWR-Commit2\"<\/a><\/p>\n
Hope to see you in Birmingham, Tuesday 26 January, 18:00 – 21:00<\/p>\n","protected":false},"excerpt":{"rendered":"
By Franck Pachot . When presenting ‘Interpreting AWR Reports – Straight to the Goal’ at UKOUG TECH15 I had a very good question about the Statspack report I read which had log file sync much smaller than user commits. I realized that this needs a longer explanation, and that my slide is very misleading because […]<\/p>\n","protected":false},"author":27,"featured_media":6796,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[229],"tags":[422,96,69],"type_dbi":[],"class_list":["post-6793","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-database-administration-monitoring","tag-awr","tag-oracle","tag-statspack"],"acf":[],"yoast_head":"\nlog file sync \/ user commits - dbi Blog<\/title>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"log file sync \/ user commits\" \/>\n<meta property=\"og:description\" content=\"By Franck Pachot . When presenting ‘Interpreting AWR Reports – Straight to the Goal’ at UKOUG TECH15 I had a very good question about the Statspack report I read which had log file sync much smaller than user commits. I realized that this needs a longer explanation, and that my slide is very misleading because […]\" \/>\n<meta property=\"og:url\" content=\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\" \/>\n<meta property=\"og:site_name\" content=\"dbi Blog\" \/>\n<meta property=\"article:published_time\" content=\"2016-01-10T18:29:21+00:00\" \/>\n<meta property=\"og:image\" content=\"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg\" \/>\n\t<meta property=\"og:image:width\" content=\"605\" \/>\n\t<meta property=\"og:image:height\" content=\"452\" \/>\n\t<meta property=\"og:image:type\" content=\"image\/jpeg\" \/>\n<meta name=\"author\" content=\"Oracle Team\" \/>\n<meta name=\"twitter:card\" content=\"summary_large_image\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"Oracle Team\" \/>\n\t<meta name=\"twitter:label2\" content=\"Est. reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"4 minutes\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\/\/schema.org\",\"@graph\":[{\"@type\":\"Article\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#article\",\"isPartOf\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\"},\"author\":{\"name\":\"Oracle Team\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/#\/schema\/person\/66ab87129f2d357f09971bc7936a77ee\"},\"headline\":\"log file sync \/ user commits\",\"datePublished\":\"2016-01-10T18:29:21+00:00\",\"mainEntityOfPage\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\"},\"wordCount\":599,\"commentCount\":0,\"image\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage\"},\"thumbnailUrl\":\"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg\",\"keywords\":[\"AWR\",\"Oracle\",\"Statspack\"],\"articleSection\":[\"Database Administration & Monitoring\"],\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"CommentAction\",\"name\":\"Comment\",\"target\":[\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#respond\"]}]},{\"@type\":\"WebPage\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\",\"url\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\",\"name\":\"log file sync \/ user commits - dbi Blog\",\"isPartOf\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/#website\"},\"primaryImageOfPage\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage\"},\"image\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage\"},\"thumbnailUrl\":\"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg\",\"datePublished\":\"2016-01-10T18:29:21+00:00\",\"author\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/#\/schema\/person\/66ab87129f2d357f09971bc7936a77ee\"},\"breadcrumb\":{\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/\"]}]},{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage\",\"url\":\"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg\",\"contentUrl\":\"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg\",\"width\":605,\"height\":452},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Accueil\",\"item\":\"https:\/\/www.dbi-services.com\/blog\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"log file sync \/ user commits\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/#website\",\"url\":\"https:\/\/www.dbi-services.com\/blog\/\",\"name\":\"dbi Blog\",\"description\":\"\",\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\/\/www.dbi-services.com\/blog\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-US\"},{\"@type\":\"Person\",\"@id\":\"https:\/\/www.dbi-services.com\/blog\/#\/schema\/person\/66ab87129f2d357f09971bc7936a77ee\",\"name\":\"Oracle Team\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\/\/secure.gravatar.com\/avatar\/f711f7cd2c9b09bf2627133755b569fb5be0694810cfd33033bdd095fedba86d?s=96&d=mm&r=g\",\"url\":\"https:\/\/secure.gravatar.com\/avatar\/f711f7cd2c9b09bf2627133755b569fb5be0694810cfd33033bdd095fedba86d?s=96&d=mm&r=g\",\"contentUrl\":\"https:\/\/secure.gravatar.com\/avatar\/f711f7cd2c9b09bf2627133755b569fb5be0694810cfd33033bdd095fedba86d?s=96&d=mm&r=g\",\"caption\":\"Oracle Team\"},\"url\":\"https:\/\/www.dbi-services.com\/blog\/author\/oracle-team\/\"}]}<\/script>\n<!-- \/ Yoast SEO Premium plugin. -->","yoast_head_json":{"title":"log file sync \/ user commits - dbi Blog","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/","og_locale":"en_US","og_type":"article","og_title":"log file sync \/ user commits","og_description":"By Franck Pachot . When presenting ‘Interpreting AWR Reports – Straight to the Goal’ at UKOUG TECH15 I had a very good question about the Statspack report I read which had log file sync much smaller than user commits. I realized that this needs a longer explanation, and that my slide is very misleading because […]","og_url":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/","og_site_name":"dbi Blog","article_published_time":"2016-01-10T18:29:21+00:00","og_image":[{"width":605,"height":452,"url":"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg","type":"image\/jpeg"}],"author":"Oracle Team","twitter_card":"summary_large_image","twitter_misc":{"Written by":"Oracle Team","Est. reading time":"4 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"Article","@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#article","isPartOf":{"@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/"},"author":{"name":"Oracle Team","@id":"https:\/\/www.dbi-services.com\/blog\/#\/schema\/person\/66ab87129f2d357f09971bc7936a77ee"},"headline":"log file sync \/ user commits","datePublished":"2016-01-10T18:29:21+00:00","mainEntityOfPage":{"@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/"},"wordCount":599,"commentCount":0,"image":{"@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage"},"thumbnailUrl":"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg","keywords":["AWR","Oracle","Statspack"],"articleSection":["Database Administration & Monitoring"],"inLanguage":"en-US","potentialAction":[{"@type":"CommentAction","name":"Comment","target":["https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#respond"]}]},{"@type":"WebPage","@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/","url":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/","name":"log file sync \/ user commits - dbi Blog","isPartOf":{"@id":"https:\/\/www.dbi-services.com\/blog\/#website"},"primaryImageOfPage":{"@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage"},"image":{"@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage"},"thumbnailUrl":"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg","datePublished":"2016-01-10T18:29:21+00:00","author":{"@id":"https:\/\/www.dbi-services.com\/blog\/#\/schema\/person\/66ab87129f2d357f09971bc7936a77ee"},"breadcrumb":{"@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/"]}]},{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#primaryimage","url":"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg","contentUrl":"https:\/\/www.dbi-services.com\/blog\/wp-content\/uploads\/sites\/2\/2022\/04\/CapturePreziAWR-Commit-1.jpg","width":605,"height":452},{"@type":"BreadcrumbList","@id":"https:\/\/www.dbi-services.com\/blog\/log-file-sync-user-commits\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Accueil","item":"https:\/\/www.dbi-services.com\/blog\/"},{"@type":"ListItem","position":2,"name":"log file sync \/ user commits"}]},{"@type":"WebSite","@id":"https:\/\/www.dbi-services.com\/blog\/#website","url":"https:\/\/www.dbi-services.com\/blog\/","name":"dbi Blog","description":"","potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/www.dbi-services.com\/blog\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-US"},{"@type":"Person","@id":"https:\/\/www.dbi-services.com\/blog\/#\/schema\/person\/66ab87129f2d357f09971bc7936a77ee","name":"Oracle Team","image":{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/secure.gravatar.com\/avatar\/f711f7cd2c9b09bf2627133755b569fb5be0694810cfd33033bdd095fedba86d?s=96&d=mm&r=g","url":"https:\/\/secure.gravatar.com\/avatar\/f711f7cd2c9b09bf2627133755b569fb5be0694810cfd33033bdd095fedba86d?s=96&d=mm&r=g","contentUrl":"https:\/\/secure.gravatar.com\/avatar\/f711f7cd2c9b09bf2627133755b569fb5be0694810cfd33033bdd095fedba86d?s=96&d=mm&r=g","caption":"Oracle Team"},"url":"https:\/\/www.dbi-services.com\/blog\/author\/oracle-team\/"}]}},"_links":{"self":[{"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/posts\/6793","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/users\/27"}],"replies":[{"embeddable":true,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/comments?post=6793"}],"version-history":[{"count":0,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/posts\/6793\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/media\/6796"}],"wp:attachment":[{"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/media?parent=6793"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/categories?post=6793"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/tags?post=6793"},{"taxonomy":"type","embeddable":true,"href":"https:\/\/www.dbi-services.com\/blog\/wp-json\/wp\/v2\/type_dbi?post=6793"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}