{"id":397,"date":"2019-03-05T21:26:26","date_gmt":"2019-03-05T13:26:26","guid":{"rendered":"http:\/\/www.lisq.net\/?p=397"},"modified":"2019-03-05T21:54:16","modified_gmt":"2019-03-05T13:54:16","slug":"11gr2-control-file-enqueue-hold-time-tracking-dump","status":"publish","type":"post","link":"https:\/\/www.lisq.net\/?p=397","title":{"rendered":"11gR2 Control file enqueue hold time tracking dump"},"content":{"rendered":"<p>\u5728\u6570\u636e\u5e93trace\u65e5\u5fd7\u4e2d\uff0c\u53d1\u73b0\u6709ckpt\u7684dump\uff0c\u8bb0\u5f55\u5982\u4e0b\u5185\u5bb9<\/p>\n<pre class=\"lang:plsql decode:true\">*** 2019-03-05 16:29:42.977\r\n*** SESSION ID:(1.1) 2019-03-05 16:29:42.977\r\n*** CLIENT ID:() 2019-03-05 16:29:42.977\r\n*** SERVICE NAME:() 2019-03-05 16:29:42.977\r\n*** MODULE NAME:() 2019-03-05 16:29:42.977\r\n*** ACTION NAME:() 2019-03-05 16:29:42.977\r\n\r\nControl file enqueue hold time tracking dump at time: 793940\r\n  1: 4370ms (rw) file: krsr.c line: 6036 count: 140720308486145 total: 4370ms time: 793059\r\n  2: 4330ms (rw) file: krsr.c line: 3722 count: 140720308486145 total: 4330ms time: 793055<\/pre>\n<p>\u8be5\u95ee\u9898\u53ef\u5ffd\u7565\u4e14\u53ef\u4ee5\u901a\u8fc7\u8c03\u6574\u9690\u542b\u53c2\u6570\u5173\u95ed\u8be5trace<\/p>\n<p>MOS\u6587\u6863\u4e2d\u300aMinact-Scn Master-Status: Grec-Scn Messages In Trace File (Doc ID 1361567.1)\u300b\u8bb0\u5f55\u5982\u4e0b<\/p>\n<pre class=\"lang:plsql decode:true\">APPLIES TO:\r\nOracle Database - Enterprise Edition - Version 11.2.0.1 and later\r\nInformation in this document applies to any platform.\r\nSYMPTOMS\r\n On 11gR2, the following messages are generated in CKPT traces:\r\n\r\nControl file enqueue hold time tracking dump at time: 1670479\r\n 1: 5268ms (ro) file: kcf.c line: 4726 count: 1 total: 5268ms time: 1670016\r\n 2: 2240ms (rw) file: kct.c line: 2522 count: 1 total: 2240ms time: 1670019\r\n 3: 941ms (ro) file: kcrr.c line: 3594 count: 1 total: 941ms time: 1670198\r\n 4: 800ms (rw) file: kcv.c line: 15856 count: 1 total: 800ms time: 1670017\r\nControl file enqueue hold time tracking dump at time: 1672300\r\n\r\nCAUSE\r\nThis is an expected behavior starting with the release of 11gR2.\r\n\r\nNew controlfile enqueue hold time tracking statistics have been added in 11.2 to aid diagnosis of controlfile transaction related performance related issues:\r\n \r\nControl File Enqueue AWR Statistics:\r\n* max cf enq hold time - The maximum amount of time in milliseconds a client has held the control file enqueue.\r\n* total cf enq hold time - The total amount of time in milliseconds all clients have held the control file enqueue.\r\n* total number of cf enq holders - The total number of times clients have held the control file enqueue.\r\n \r\nPeriodically, the CKPT process dumps statistics for the top N control file enqueue holders.\r\nN defaults to 10, but can be modified with the static hidden parameter:\r\n_controlfile_enqueue_holding_time_tracking_size.The dump looks like the following:\r\n\r\n\r\nPreface: \"Control file enqueue hold time tracking dump at time: [relative time]\".\r\n \r\n* a. Time the client has held the control file enqueue.\r\n* b. Type of client's control file enqueue transaction - rw or ro.\r\n* c. File name where the client obtained control file enqueue.\r\n* d. Line number where the client obtained control file enqueue.\r\n* e. Number of times the client has held the control file enqueue since it became a member of the top N.\r\n* f. Total time the client has held the control file in all those times from [e].\r\n* g. Relative time the client obtained the control file enqueue from [a].\r\n\r\n\r\nSQL&gt; col value for a24\r\nSQL&gt; col description for a70\r\nSQL&gt; set linesize 180\r\nSQL&gt; select a.ksppinm name,b.ksppstvl value,a.ksppdesc description\r\n  2    from x$ksppi a,x$ksppcv b\r\n  3    where a.inst_id = USERENV ('Instance')\r\n  4     and b.inst_id = USERENV ('Instance')\r\n  5     and a.indx = b.indx\r\n  6     and upper(a.ksppinm) LIKE upper('%&amp;param%')\r\n  7  order by name\r\n  8  \/\r\n\r\n\r\nSOLUTION\r\n The way to shut off is set _controlfile_enqueue_holding_time_tracking_size = 0 then restart the database\r\n \r\n-- spfile\r\nalter system set \"_controlfile_enqueue_holding_time_tracking_size\"=0 scope=spfile;\r\n \r\n-- pfile\r\n_controlfile_enqueue_holding_time_tracking_size=0\r\n \r\nRestart database<\/pre>\n<p>&nbsp;<\/p>\n","protected":false},"excerpt":{"rendered":"<p>\u5728\u6570\u636e\u5e93trace\u65e5\u5fd7\u4e2d\uff0c\u53d1\u73b0\u6709ckpt\u7684dump\uff0c\u8bb0\u5f55\u5982\u4e0b &hellip;<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"jetpack_post_was_ever_published":false,"_jetpack_newsletter_access":"","_jetpack_dont_email_post_to_subs":false,"_jetpack_newsletter_tier_id":0,"_jetpack_memberships_contains_paywalled_content":false,"_jetpack_memberships_contains_paid_content":false,"footnotes":"","jetpack_publicize_message":"","jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":true,"jetpack_social_options":{"image_generator_settings":{"template":"highway","default_image_id":0,"enabled":false},"version":2}},"categories":[15,2],"tags":[],"class_list":["post-397","post","type-post","status-publish","format-standard","hentry","category-bug","category-oracle"],"jetpack_publicize_connections":[],"jetpack_featured_media_url":"","jetpack_sharing_enabled":true,"jetpack_shortlink":"https:\/\/wp.me\/p7zRbQ-6p","_links":{"self":[{"href":"https:\/\/www.lisq.net\/index.php?rest_route=\/wp\/v2\/posts\/397","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.lisq.net\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.lisq.net\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.lisq.net\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.lisq.net\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=397"}],"version-history":[{"count":1,"href":"https:\/\/www.lisq.net\/index.php?rest_route=\/wp\/v2\/posts\/397\/revisions"}],"predecessor-version":[{"id":398,"href":"https:\/\/www.lisq.net\/index.php?rest_route=\/wp\/v2\/posts\/397\/revisions\/398"}],"wp:attachment":[{"href":"https:\/\/www.lisq.net\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=397"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.lisq.net\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=397"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.lisq.net\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=397"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}