This page has been permanently moved. PleaseCLICK HERE to be redirected.
Thanks, Craig.How To Change The Priority Of Oracle Background Processes
Before you get in a huf, it can be done! You can change an Oracle Database background process
priority through an instance parameter! I'm not saying it's a good idea, but it can be done.
In this post I explore how to make the change, just how far you can take it and when you may want to consider changing an Oracle background process priority.
To get your adrenaline going, check out the instance parameter _high_priority_processes from one of your production Oracle system with a version of 11 or greater. Here is an example using my OSM tool, ipx.sql on my Oracle Database version 12.1.0.2.0.SQL> @ipx _highest_priority_processesDatabase: prod40 27-OCT-14 02:22pmReport: ipx.sql OSM by OraPub, Inc. Page 1 Display ALL Instance ParametersInstance Parameter and Value Description Dflt?-------------------------------------------------- -------------------- -----_highest_priority_processes = VKTM Highest Priority TRUE Process Name MaskThen at the Linux prompt, I did:
$ ps -eo pid,class,pri,nice,time,args | grep prod40 2879 TS 19 0 00:00:00 ora_pmon_prod40 2881 TS 19 0 00:00:01 ora_psp0_prod40 2883 RR 41 - 00:02:31 ora_vktm_prod40 2889 TS 19 0 00:00:01 ora_mman_prod40 2903 TS 19 0 00:00:00 ora_lgwr_prod40 2905 TS 19 0 00:00:01 ora_ckpt_prod40 2907 TS 19 0 00:00:00 ora_lg00_prod40 2911 TS 19 0 00:00:00 ora_lg01_prod40...Notice the "pri" for priority of the ora_vktm_prod40 process? It is set to 41 while all the rest of the Oracle background processes are set to the default of 19. Very cool, eh?
Surprised By What I Found
Surprised? Yes, surprised because changing Oracle process priority is a pandoras box. Just imagine if an Oracle server (i.e., foreground) process has its priority lowered just a little and then attempts to acquire a latch or a mutex? If it doesn't get the latch quickly, I might never ever get it!
From a user experience perspective, sometimes performance really quick and other times the application just hangs.
This actually happened to a customer of mine years ago when the OS started reducing a process's priority after it consumed a certain amount of CPU. I learned that when it comes to Oracle processes, they are programed to expect an even process priority playing field. If you try to "game" the situation, do so at your own risk... not Oracle's.
Then why did Oracle Corporation allow background process priority to be changed. And why did Oracle Corporation actually change a background processes priority?!
Doing A Little Exploration
It turns out there are a number of "priority" related underscore instance parameters! On my 11.2.0.1.0 system there 6 "priority" parameters. On my 12.1.0.1.0 system there are 8 "priority" parameters. On my 12.1.0.2.0 system there are 13 "priority" parameters! So clearly Oracle is making changes! In all cases, the parameter I'm focusing on, "_high_priority_processes" exists.
In this posting, I'm going to focus on my Oracle Database 12c version 12.1.0.2.0 system. While you may see something different in your environment, the theme will be the same.
While I'll be blogging about all four of the below parameters, in this posting my focus will be on the _high_priority_processes parameter. Below are the defaults on my system:
_high_priority_processes LMS*_highest_priority_processes VKTM_os_sched_high_priority 1_os_sched_highest_priority 1
Messing With The LGWR Background Processes
I'm not testing this on a RAC system, so I don't have an LMS background process. When I saw the "LMS*" I immediately thought, "regular expression." Hmmm... I wonder if I can change the LGWR background process. So I made the instance parameter change and recycled the instance. Below shows the instance parameter change:
SQL> @ipx _high_priority_processesDatabase: prod40 27-OCT-14 02:36pmReport: ipx.sql OSM by OraPub, Inc. Page 1 Display ALL Instance ParametersInstance Parameter and Value Description Dflt?-------------------------------------------------- -------------------- -----_high_priority_processes = LMS*|LGWR High Priority FALSE Process Name Mask
Below is an operating system perspective using the ps command:
ps -eo pid,class,pri,nice,time,args | grep prod40... 5521 RR 41 - 00:00:00 ora_vktm_prod40 5539 TS 19 0 00:00:00 ora_dbw0_prod40 5541 RR 41 - 00:00:00 ora_lgwr_prod40 5545 TS 19 0 00:00:00 ora_ckpt_prod40 5547 TS 19 0 00:00:00 ora_lg00_prod40 5551 TS 19 0 00:00:00 ora_lg01_prod40...
How Far Can I Take This?
At this point in my journey, my mind was a blaze! The log file sync wait event can be really difficult to deal with and especially so when there is a CPU bottleneck. Hmmm... Perhaps I can increase the priority of all the log writer background processes?
So I made the instance parameter change and recycled the instance. Below shows the instance parameter change:
SQL> @ipx _high_priority_processesDatabase: prod40 27-OCT-14 02:44pmReport: ipx.sql OSM by OraPub, Inc. Page 1 Display ALL Instance ParametersInstance Parameter and Value Description Dflt?-------------------------------------------------- -------------------- -----_high_priority_processes = LMS*|LG* High Priority FALSE Process Name Mask
Below is an operating system perspective using the ps command:
ps -eo pid,class,pri,nice,time,args | grep prod40... 5974 TS 19 0 00:00:00 ora_psp0_prod40 5976 RR 41 - 00:00:00 ora_vktm_prod40 5994 TS 19 0 00:00:00 ora_dbw0_prod40 5996 RR 41 - 00:00:00 ora_lgwr_prod40 6000 TS 19 0 00:00:00 ora_ckpt_prod40 6002 RR 41 - 00:00:00 ora_lg00_prod40 6008 RR 41 - 00:00:00 ora_lg01_prod40 6014 TS 19 0 00:00:00 ora_lreg_prod40...
So now all the log writer background processes have a high priority. My hope would be that if there is an OS CPU bottleneck and the log writer background processes wanted more CPU, I now have the power to give that to them! Another tool in my performance tuning arsenal!
Security Hole?
At this point, my exuberance began to turn into paranoia. I thought, "Perhaps I can increase the priority of an Oracle server process or perhaps any process." If so, that would be a major Oracle Database security hole.
With fingers trembling, I changed the instance parameters to match an Oracle server process and recycled the instance. Below shows the instance parameter change:
SQL> @ipx _high_priority_processesDatabase: prod40 27-OCT-14 02:52pmReport: ipx.sql OSM by OraPub, Inc. Page 1 Display ALL Instance ParametersInstance Parameter and Value Description Dflt?-------------------------------------------------- -------------------- -----_high_priority_processes = High Priority FALSELMS*|LG*|oracleprod40 Process Name Mask
Below is an operating system perspective using the ps command:
$ ps -eo pid,class,pri,nice,time,args | grep prod40... 6360 TS 19 0 00:00:00 ora_psp0_prod40 6362 RR 41 - 00:00:00 ora_vktm_prod40 6366 TS 19 0 00:00:00 ora_gen0_prod40 6382 RR 41 - 00:00:00 ora_lgwr_prod40 6386 TS 19 0 00:00:00 ora_ckpt_prod40 6388 RR 41 - 00:00:00 ora_lg00_prod40 6394 RR 41 - 00:00:00 ora_lg01_prod40 6398 TS 19 0 00:00:00 ora_reco_prod40... 6644 TS 19 0 00:00:00 oracleprod40......
OK, that didn't work so how about this?
SQL> @ipx _high_priority_processesDatabase: prod40 27-OCT-14 02:55pmReport: ipx.sql OSM by OraPub, Inc. Page 1 Display ALL Instance ParametersInstance Parameter and Value Description Dflt?-------------------------------------------------- -------------------- -----_high_priority_processes = High Priority FALSELMS*|LG*|*oracle* Process Name Mask
Let's see what happened at the OS.
$ ps -eo pid,class,pri,nice,time,args | grep prod40... 6701 RR 41 - 00:00:00 ora_vktm_prod40 6705 RR 41 - 00:00:00 ora_gen0_prod40 6709 RR 41 - 00:00:00 ora_mman_prod40 6717 RR 41 - 00:00:00 ora_diag_prod40 6721 RR 41 - 00:00:00 ora_dbrm_prod40 6725 RR 41 - 00:00:00 ora_vkrm_prod40 6729 RR 41 - 00:00:00 ora_dia0_prod40 6733 RR 41 - 00:00:00 ora_dbw0_prod40... 6927 RR 41 - 00:00:00 ora_p00m_prod40 6931 RR 41 - 00:00:00 ora_p00n_prod40 7122 TS 19 0 00:00:00 oracleprod40 ... 7124 RR 41 - 00:00:00 ora_qm02_prod40 7128 RR 41 - 00:00:00 ora_qm03_prod40
Oh Oh... That's not good! Now EVERY Oracle background process has a higher priority and my Oracle server process does not.
So my "*" wildcard caused all the Oracle processes to be included. If all the processes a high prioirty, then the log writer processes have no advantage over the others. And to make matters even worse, my goal of increasing the server process priority did not occur.
However, this is actually very good news because it appears this is not an Oracle Database security hole! To me, it looks like the priority parameter is applied during the instance startup for just the background processes. Since my server process was started after the instance was started and for sure not included in the list of background processes, its priority was not affected. Good news for security, not as good of news for a performance optimizing fanatic such as myself.
Should I Ever Increase A Background Process Priority?
Now that we know how to increase an Oracle Database background process priority, when would we ever want to do this? The short answer is probably never. But the long answer is the classic, "it depends."
Let me give you an example. Suppose there is an OS CPU bottleneck and the log writer background processes are consuming lots of CPU while handling all the associated memory management when server process issues a commit. In this situation, performance may benefit by making it easier for the log writer processes to get CPU cycles, therefore improving performance. But don't even think about doing this unless there is a CPU bottleneck. And even then, be very very careful.
In my next block posting, I'll detail an experiment where I changed the log writer background processes priority.
Thanks for reading!
Craig.
إظهار الرسائل ذات التسميات Background. إظهار كافة الرسائل
إظهار الرسائل ذات التسميات Background. إظهار كافة الرسائل
الجمعة، 15 مايو 2015
Does Increasing An Oracle Background Process OS Priority Improve Performance?
This page has been permanently moved. PleaseCLICK HERE to be redirected.
Thanks, Craig.Does Increasing An Oracle Background Process OS Priority Improve Performance?
Does increasing an Oracle Database background process operating system priority improve performance? As you might expect, the answer is, "It depends."
In this posting I will explain the results of an experiment where I increase the Oracle Database 12c log writer background processes operating system priority.
In my experiment I created a clear CPU bottleneck and the top wait event was log file parallel write. I gathered some data. Next I increased all the log writer background process priorities. Again, I gathered some data and then I analyzed the two data sets. The results were disappointing, not surprising, but a fundamental rule in performance tuning was demonstrated and reinforced.
You can download the "analysis pack" which contains the raw experimental data, histogram, statistical R results and the R statical package commands HERE. You can download total time delta reporting script (ttpctx.sql) I show below, which is contained within my OraPub System Monitor (OSM) Toolkit HERE.
Before I could gather some data, I needed to create the appropriate system load, the data gather scripts and the data analysis scripts. Here's a quick overview of each.
Increasing The LGWR Processes PriorityIf you are not familiar with changing Oracle Database background OS process priority, I blogged about how to do this HERE.
My experiment consisted of creating two situations and statistically comparing them to see if increasing the LGWR background process OS priority increased performance. The only difference in the "two situations" was the instance parameter, _high_priority_processes. For the "normal priority" part of the experiment, the default "LMS*|VKTM" was used. For the "high priority" part of the experiment the parameter was changed to "LMS*|VKTM|LG*". The "LG*" caused the increase in the Linux OS priority of all log writer processes from the default 19 to 41.
Ready for some version specifics? Oracle continues to make OS priority related instance parameter changes... even within 12c releases. Since this experiment was done with Oracle Database version 12.1.0.1.0 the parameter default was "LMS*|VKTM" not "LMS*" as with version 12.1.0.2.0. Also, in 12.1.0.2.0 VKTM is placed into a new parameter, _highest_priority_processes.
Generating The DML With CPU Bottleneck Load
To generate the DML workload, I used my OP Load Generator. You can download it HERE. It's quick, easy and I'm familiar with it. I kept increasing the number of DML processes until the CPU utilization was pegged at 100%. While the database server was clearly out of CPU power, the log writer background processes were rarely seen as the top CPU consuming process. I used the "top" program to monitor the process activity. The top CPU consuming processes were almost always the Oracle server/foreground/shadow processes. As I'll explain in the Results section below, this has significant ramifications on the results.
Oracle Time Based Analysis Summary
The data collection script was similar to the one I used back in 2012 when collecting data regarding Oracle's commit write facility. Essentially, I collected multiple three minute samples of the delta elapsed time, user commits, total non-idle wait time and CPU consumption. In both the normal and high priority runs, around 99% of the database time was CPU consumption and 1% of the time Oracle non-idle wait time. Also the top wait event (~70%) was log file parallel write (display name: log file redo write).
If you want master an Oracle Time Based Analysis, check out my online seminar, Tuning Oracle Using An AWR Report. It will teach you how to using an AWR report to optimize Oracle performance so users will feel the difference.
The OraPub System Monitor Toolkit script ttpctx.sql report below was taken during the "normal priority" log writer load.
SQL> @ttpctxDatabase: prod35 16-MAY-14 06:07pmReport: ttpctx.sql OSM by OraPub, Inc. Page 1 Total Time Activity (39 sec interval) Avg Time Time WaitTime Component % TT % WT Waited (ms) (sec) Count(k)------------------------------------- ------- ------- ----------- ----------- --------CPU consumption: Oracle SP + BG procs 98.91 0.00 0.000 238.716 0log file redo write 0.73 67.56 8.082 1.770 0control file parallel write 0.18 16.41 33.077 0.430 0target log write size 0.05 4.20 6.111 0.110 0oracle thread bootstrap 0.03 3.05 40.000 0.080 0os thread creation 0.02 1.53 20.000 0.040 0commit: log file sync 0.01 0.76 10.000 0.020 0enq: CR - block range reuse ckpt 0.01 0.76 20.000 0.020 0Disk file operations I/O 0.00 0.00 0.000 0.000 0
The OSM report below was taken during the "high priority" log writer load.
SQL> @ttpctxDatabase: prod35 16-MAY-14 09:25pmReport: ttpctx.sql OSM by OraPub, Inc. Page 1 Total Time Activity (41 sec interval) Avg Time Time WaitTime Component % TT % WT Waited (ms) (sec) Count(k)------------------------------------- ------- ------- ----------- ----------- --------CPU consumption: Oracle SP + BG procs 98.92 0.00 0.000 238.733 0log file redo write 0.83 77.01 8.272 2.010 0control file parallel write 0.08 7.28 14.615 0.190 0target log write size 0.05 4.98 5.909 0.130 0oracle thread bootstrap 0.03 3.07 40.000 0.080 0os thread creation 0.02 1.92 25.000 0.050 0commit: log file sync 0.01 0.77 10.000 0.020 0enq: CR - block range reuse ckpt 0.01 0.77 20.000 0.020 0enq: RO - fast object reuse 0.00 0.38 10.000 0.010 0
Data Collection
For the normal priority load 27 three minute samples where collected. For the high priority situation there were 30 three minute samples collected. (I forgot why there was only 27 samples collected for the normal priority.) I collected the elapsed time, total non-idle wait time, total CPU consumption (v$sys_time_model: db_cpu + background cpu time) and total user commits.
In this experiment more user commits processed per second means better performance.
Experimental Results
I used the free statistics package "R" (www.r-project.org) to analyze the data. I demonstrate how to get, install and use "R" in my online video seminar, Using Skewed Data To Your Advantage.
With the normal log writer process priority, an average of 984.5 commits/sec and a median of 983.0 commits/sec occurred. With the LG* high process priority, an average of 993.6 commits/sec and a median of 991.0 commits/sec occurred. While the "high priority" situation was able to process more commits per second, is this statistically significant?
The red "smoothed" histogram is the normal priority situation and the blue smoothed histogram is when the log writers were set to the higher priority. The more separated the two histograms the more "different" the sample sets, the more likely there is a statistically significant difference and the more likely a user would feel the difference. Looking at the above histograms plot, there does not appear to be a real difference. But let's do a proper significance test!
Because both sample sets are normally distributed (details are in the Analysis Pack), I could use a simple t-test. R produced a p-value of 0.04451. To be statistically "different" I want the p-value to be less than 0.05 and it is. What does this mean?
While statistically and numerically the commit rates are different, I wouldn't expect any special performance tuning award! In fact, the hassles with cycling a production instance and setting underscore/hidden parameters would make it very unlikely I would increase the OS priority of the log writer background processes. I want to see a big performance difference.
To Summarize... What I Learned... Again
This situation is a perfect example of focusing on the wrong thing! While there is a clear operating system CPU bottleneck and the top wait event is about redo, the log writers are not suffering from a want/need of CPU resources. I suspect the server processes want more CPU resources, but they are NOT the processes we increased their OS priority.
If the log writers were suffering from a lack of CPU resources and fighting for CPU resources, I would expect to see them consuming CPU resources along with the Oracle server processes. And I would definitely expect to see them near the top of the "top" process monitor... especially when their priority has been increased!
Because of this "misguided" tuning effort, this experiment does not build a case for or against changing the log writer priority. What it reinforces is in our quest to optimize performance, make sure we focus on the right thing.
As a side note, this is a great statistical analysis example for two reasons. First, our samples sets look similar, but statistically they are not. Second, while they are statistically different, the performance impact will not be very different. And my guess is the users won't feel a thing... except frustration and anger.
To Super Summarize
When considering increasing a background process's operating system priority, make sure the process is in need of CPU and is not able to get it. In this situation, the DBA could have been mislead by the CPU bottleneck. But upon closer inspection of the log writers from an operating system perspective and knowing the wait event "log file parallel write" is probably more about IO than CPU (Oracle perspective) it would be unlikely that increasing the log writer processes OS priority would help increase the commits per second.
Thanks for reading!
Craig.
Thanks, Craig.Does Increasing An Oracle Background Process OS Priority Improve Performance?
Does increasing an Oracle Database background process operating system priority improve performance? As you might expect, the answer is, "It depends."
In this posting I will explain the results of an experiment where I increase the Oracle Database 12c log writer background processes operating system priority.
In my experiment I created a clear CPU bottleneck and the top wait event was log file parallel write. I gathered some data. Next I increased all the log writer background process priorities. Again, I gathered some data and then I analyzed the two data sets. The results were disappointing, not surprising, but a fundamental rule in performance tuning was demonstrated and reinforced.
You can download the "analysis pack" which contains the raw experimental data, histogram, statistical R results and the R statical package commands HERE. You can download total time delta reporting script (ttpctx.sql) I show below, which is contained within my OraPub System Monitor (OSM) Toolkit HERE.
Before I could gather some data, I needed to create the appropriate system load, the data gather scripts and the data analysis scripts. Here's a quick overview of each.
Increasing The LGWR Processes PriorityIf you are not familiar with changing Oracle Database background OS process priority, I blogged about how to do this HERE.
My experiment consisted of creating two situations and statistically comparing them to see if increasing the LGWR background process OS priority increased performance. The only difference in the "two situations" was the instance parameter, _high_priority_processes. For the "normal priority" part of the experiment, the default "LMS*|VKTM" was used. For the "high priority" part of the experiment the parameter was changed to "LMS*|VKTM|LG*". The "LG*" caused the increase in the Linux OS priority of all log writer processes from the default 19 to 41.
Ready for some version specifics? Oracle continues to make OS priority related instance parameter changes... even within 12c releases. Since this experiment was done with Oracle Database version 12.1.0.1.0 the parameter default was "LMS*|VKTM" not "LMS*" as with version 12.1.0.2.0. Also, in 12.1.0.2.0 VKTM is placed into a new parameter, _highest_priority_processes.
Generating The DML With CPU Bottleneck Load
To generate the DML workload, I used my OP Load Generator. You can download it HERE. It's quick, easy and I'm familiar with it. I kept increasing the number of DML processes until the CPU utilization was pegged at 100%. While the database server was clearly out of CPU power, the log writer background processes were rarely seen as the top CPU consuming process. I used the "top" program to monitor the process activity. The top CPU consuming processes were almost always the Oracle server/foreground/shadow processes. As I'll explain in the Results section below, this has significant ramifications on the results.
Oracle Time Based Analysis Summary
The data collection script was similar to the one I used back in 2012 when collecting data regarding Oracle's commit write facility. Essentially, I collected multiple three minute samples of the delta elapsed time, user commits, total non-idle wait time and CPU consumption. In both the normal and high priority runs, around 99% of the database time was CPU consumption and 1% of the time Oracle non-idle wait time. Also the top wait event (~70%) was log file parallel write (display name: log file redo write).
If you want master an Oracle Time Based Analysis, check out my online seminar, Tuning Oracle Using An AWR Report. It will teach you how to using an AWR report to optimize Oracle performance so users will feel the difference.
The OraPub System Monitor Toolkit script ttpctx.sql report below was taken during the "normal priority" log writer load.
SQL> @ttpctxDatabase: prod35 16-MAY-14 06:07pmReport: ttpctx.sql OSM by OraPub, Inc. Page 1 Total Time Activity (39 sec interval) Avg Time Time WaitTime Component % TT % WT Waited (ms) (sec) Count(k)------------------------------------- ------- ------- ----------- ----------- --------CPU consumption: Oracle SP + BG procs 98.91 0.00 0.000 238.716 0log file redo write 0.73 67.56 8.082 1.770 0control file parallel write 0.18 16.41 33.077 0.430 0target log write size 0.05 4.20 6.111 0.110 0oracle thread bootstrap 0.03 3.05 40.000 0.080 0os thread creation 0.02 1.53 20.000 0.040 0commit: log file sync 0.01 0.76 10.000 0.020 0enq: CR - block range reuse ckpt 0.01 0.76 20.000 0.020 0Disk file operations I/O 0.00 0.00 0.000 0.000 0
The OSM report below was taken during the "high priority" log writer load.
SQL> @ttpctxDatabase: prod35 16-MAY-14 09:25pmReport: ttpctx.sql OSM by OraPub, Inc. Page 1 Total Time Activity (41 sec interval) Avg Time Time WaitTime Component % TT % WT Waited (ms) (sec) Count(k)------------------------------------- ------- ------- ----------- ----------- --------CPU consumption: Oracle SP + BG procs 98.92 0.00 0.000 238.733 0log file redo write 0.83 77.01 8.272 2.010 0control file parallel write 0.08 7.28 14.615 0.190 0target log write size 0.05 4.98 5.909 0.130 0oracle thread bootstrap 0.03 3.07 40.000 0.080 0os thread creation 0.02 1.92 25.000 0.050 0commit: log file sync 0.01 0.77 10.000 0.020 0enq: CR - block range reuse ckpt 0.01 0.77 20.000 0.020 0enq: RO - fast object reuse 0.00 0.38 10.000 0.010 0
Data Collection
For the normal priority load 27 three minute samples where collected. For the high priority situation there were 30 three minute samples collected. (I forgot why there was only 27 samples collected for the normal priority.) I collected the elapsed time, total non-idle wait time, total CPU consumption (v$sys_time_model: db_cpu + background cpu time) and total user commits.
In this experiment more user commits processed per second means better performance.
Experimental Results
I used the free statistics package "R" (www.r-project.org) to analyze the data. I demonstrate how to get, install and use "R" in my online video seminar, Using Skewed Data To Your Advantage.
With the normal log writer process priority, an average of 984.5 commits/sec and a median of 983.0 commits/sec occurred. With the LG* high process priority, an average of 993.6 commits/sec and a median of 991.0 commits/sec occurred. While the "high priority" situation was able to process more commits per second, is this statistically significant?The red "smoothed" histogram is the normal priority situation and the blue smoothed histogram is when the log writers were set to the higher priority. The more separated the two histograms the more "different" the sample sets, the more likely there is a statistically significant difference and the more likely a user would feel the difference. Looking at the above histograms plot, there does not appear to be a real difference. But let's do a proper significance test!
Because both sample sets are normally distributed (details are in the Analysis Pack), I could use a simple t-test. R produced a p-value of 0.04451. To be statistically "different" I want the p-value to be less than 0.05 and it is. What does this mean?
While statistically and numerically the commit rates are different, I wouldn't expect any special performance tuning award! In fact, the hassles with cycling a production instance and setting underscore/hidden parameters would make it very unlikely I would increase the OS priority of the log writer background processes. I want to see a big performance difference.
To Summarize... What I Learned... Again
This situation is a perfect example of focusing on the wrong thing! While there is a clear operating system CPU bottleneck and the top wait event is about redo, the log writers are not suffering from a want/need of CPU resources. I suspect the server processes want more CPU resources, but they are NOT the processes we increased their OS priority.If the log writers were suffering from a lack of CPU resources and fighting for CPU resources, I would expect to see them consuming CPU resources along with the Oracle server processes. And I would definitely expect to see them near the top of the "top" process monitor... especially when their priority has been increased!
Because of this "misguided" tuning effort, this experiment does not build a case for or against changing the log writer priority. What it reinforces is in our quest to optimize performance, make sure we focus on the right thing.
As a side note, this is a great statistical analysis example for two reasons. First, our samples sets look similar, but statistically they are not. Second, while they are statistically different, the performance impact will not be very different. And my guess is the users won't feel a thing... except frustration and anger.
To Super Summarize
When considering increasing a background process's operating system priority, make sure the process is in need of CPU and is not able to get it. In this situation, the DBA could have been mislead by the CPU bottleneck. But upon closer inspection of the log writers from an operating system perspective and knowing the wait event "log file parallel write" is probably more about IO than CPU (Oracle perspective) it would be unlikely that increasing the log writer processes OS priority would help increase the commits per second.
Thanks for reading!
Craig.
Can A Background Process Impact A Foreground Process And Its Database Time?
This page has been permanently moved. PleaseCLICK HERE to be redirected.
Thanks, Craig.Can A Background Process Impact A Foreground Process And Its Database Time?
Have you ever heard someone say, "Background processes do not impact foreground processes because they run in the background and in parallel with foreground processes." I've heard this hundreds of times!
While doing some performance research I came across a great example of how an Oracle Database background process can directly and significantly impact a foreground process.
The above quote represents a masterfully constructed lie; it contains both a lie and a truth. The mix of a truth and a lie make understanding the reality of the situation difficult. In this post, I'll explain the truth, delve into the lie and relate it all to foreground process database time.
By the way, I am in no way saying there is something wrong with or incorrect about DB Time. I want to ensure this is clear from the very beginning of this post.
Just so there is no confusion, an Oracle foreground process is sometimes also called a server process or a shadow process. These can terms can be used interchangeably in this post.
The Truth
Clearly background and foreground processes operate in parallel. I don't think any DBA would deny this. As I frequently say, "serialization is death and parallelism is life!" A simple "ps" command will visually show both Oracle background and foreground processes at work. But this in no way implies they do not impact each other's activity and performance.
In fact, we hope they do impact each other! Can you imagine what performance would be with the background processes NOT running in parallel?! What a performance nightmare that would be. But this where the "no impact" lie lives.
The Lie
Most senior DBAs can point to a specific situation where Oracle cache buffer chain latch contention affected multiple foreground sessions. In this situation, foreground sessions were franticly trying to acquire a popular cache buffer chain latch. But this is a foreground session versus foreground session situation. While this is example is important, this post is about when a background process impacts a foreground process.
Have you every committed a transaction and it hangs while the foreground process is waiting on "log file switch (checkpoint incomplete)" or even worse "log file switch (archiving needed)" event? All the foreground process knows is that its statement can't finish because a required log switch has not occurred because a checkpoint is incomplete. What the server process does not know is the checkpoint (CKPT), the database writer (DBWR) and the log writer (LGWR) background processes are involved. There is a good chance the database writer is frantically writing dirty buffers to the database (dbf) files so the LGWR can safely overwrite the associated redo in the next online redo log.
For example, if a server process issued a commit during the checkpoint, it will wait until the checkpoint is complete and the log writer has switched and can write into the next redo log. So, while the log writer background processes is probably waiting on "log file parallel write" and the database writer is burning CPU and waiting on "db file parallel write", the foreground processes are effectively hung.
This is a classic example of how a background process can impact the performance of a foreground process.
A Demonstration Of The Lie
Here's a quick demonstration of the above situation. On an existing database in my lab, I created two 4MB redo logs and dropped all the other redo logs. I started a DML intensive workload. According to the alert.log file, the redo logs where switching every couple of seconds! Take a look at this:
$ tail -f /home/oracle/base/diag/rdbms/prod30/prod30/trace/alert*logThread 1 cannot allocate new log, sequence 2365Checkpoint not complete Current log# 4 seq# 2364 mem# 0: /home/oradata/prod30/redoA1.logMon Dec 29 11:02:09 2014Thread 1 advanced to log sequence 2365 (LGWR switch) Current log# 5 seq# 2365 mem# 0: /home/oradata/prod30/redoA2.logThread 1 cannot allocate new log, sequence 2366Checkpoint not complete Current log# 5 seq# 2365 mem# 0: /home/oradata/prod30/redoA2.logThread 1 advanced to log sequence 2366 (LGWR switch) Current log# 4 seq# 2366 mem# 0: /home/oradata/prod30/redoA1.logThread 1 cannot allocate new log, sequence 2367Checkpoint not complete Current log# 4 seq# 2366 mem# 0: /home/oradata/prod30/redoA1.logThread 1 advanced to log sequence 2367 (LGWR switch) Current log# 5 seq# 2367 mem# 0: /home/oradata/prod30/redoA2.logThread 1 cannot allocate new log, sequence 2368Checkpoint not complete Current log# 5 seq# 2367 mem# 0: /home/oradata/prod30/redoA2.logMon Dec 29 11:02:20 2014
Obviously not what you want to see on a production Oracle system! (But my guess many of you have.)
Using my OSM realtime session sampler tool (rss.sql - related blog posting HERE) I sampled the log writer every half a second. (There is only one log writer background process because this is an Oracle 11g database, not an Oracle Database 12c system.) If the log writer session showed up in v$session as an active session, it would be picked up by rss.sql. Both "ON CPU" and "WAIT" states are collected. Here is a sample of the output.
It's very obvious the log writer is doing some writing. But we can't tell from the above output if the process is impacting other sessions. It would have also been very interesting to sample the database writer also, but I didn't do that. To determine if the background processes are impacting other sessions, I needed to find a foreground session that was doing some commits. I noticed that session 133, a foreground process was busy doing some DML and committing as it processed its work. Just as with the log writer background process, I sampled this foreground process once every 0.5 second. Here's a sample of the output.
Wow. The foreground process is waiting a lot for the current checkpoint to be completed! So... this means the foreground process is being effectively halted until the background processes involved with the checkpoint have finished their work.
This is a great example of how Oracle background processes can impact the performance of an Oracle foreground process.
But let's be clear. Without the background processes, performance would be even worse. Why? Because all that work done in parallel and in the background would have to be done by each foreground process AND all that work would have to be closely controlled and coordinated. And that, would be a performance nightmare!
DB Time Impact On The Foreground Process
Just for the fun of it, I wrote a script to investigate DB Time, CPU consumption, non-idle wait time and the wait time for the "log file switch wait (checkpoint incomplete)" wait event for the foreground process mentioned above (session 133). The script simply gathers some session details, sleeps for 120 seconds, again gathers some session details, calculates the differences and displays the results. You can download the script HERE. Below is the output for the foreground process, session 133.SQL> @ckpttest.sql 133Table dropped.Table created.PL/SQL procedure successfully completed.CPU_S_DELTA NIW_S_DELTA DB_TIME_S_DELTA CHECK_IMPL_WAIT_S----------- ----------- --------------- ----------------- 2.362 117.71 119.973692 112.421 row selected.
Here is a quick description of the output columns.
CPU_S_DELTA is the CPU seconds consumed by session 133, which is the time model statistic DB CPU.NIW_S_DELTA is the non-idle wait time for session 133, in seconds.DB_TIME_S_DELTA is the DB Time statistic for session 133, which is the time model statistic DB Time.CHECK_IMPL_WAIT_S is the wait time only for event "log file switch (checkpoint incomplete)" for session 133, in seconds.
Does the time fit together as we expect? The "log file switch..." wait time is part of the non-idle wait time. The DB Time total is very close to the CPU time plus the non-idle wait time. Everything seems to add up nicely.
To summarize: Oracle background processes directly impacted the database time for a foreground process.
In Conclusion...
First, for sure Oracle foreground and background processes impact each other...by design for increased performance. Sometimes on real production Oracle Database systems things get messy and work that we hoped would be done in parallel must become momentarily serialized. The log file switch example above, is an example of this.
Second, the next time someone tells you that an Oracle background process does not impact the performance of a foreground process, ask them if they have experienced a "log file switch checkpoint incomplete" situation. Pause until they say, "Yes." Then just look at them and don't say a word. After a few seconds you may see a "oh... I get it." look on their face. But if not, simply point them to this post.
Thanks for reading and enjoy your work!
Craig.
Thanks, Craig.Can A Background Process Impact A Foreground Process And Its Database Time?
Have you ever heard someone say, "Background processes do not impact foreground processes because they run in the background and in parallel with foreground processes." I've heard this hundreds of times!
While doing some performance research I came across a great example of how an Oracle Database background process can directly and significantly impact a foreground process.
The above quote represents a masterfully constructed lie; it contains both a lie and a truth. The mix of a truth and a lie make understanding the reality of the situation difficult. In this post, I'll explain the truth, delve into the lie and relate it all to foreground process database time.
By the way, I am in no way saying there is something wrong with or incorrect about DB Time. I want to ensure this is clear from the very beginning of this post.
Just so there is no confusion, an Oracle foreground process is sometimes also called a server process or a shadow process. These can terms can be used interchangeably in this post.
The Truth
Clearly background and foreground processes operate in parallel. I don't think any DBA would deny this. As I frequently say, "serialization is death and parallelism is life!" A simple "ps" command will visually show both Oracle background and foreground processes at work. But this in no way implies they do not impact each other's activity and performance.
In fact, we hope they do impact each other! Can you imagine what performance would be with the background processes NOT running in parallel?! What a performance nightmare that would be. But this where the "no impact" lie lives.
The Lie
Most senior DBAs can point to a specific situation where Oracle cache buffer chain latch contention affected multiple foreground sessions. In this situation, foreground sessions were franticly trying to acquire a popular cache buffer chain latch. But this is a foreground session versus foreground session situation. While this is example is important, this post is about when a background process impacts a foreground process.
Have you every committed a transaction and it hangs while the foreground process is waiting on "log file switch (checkpoint incomplete)" or even worse "log file switch (archiving needed)" event? All the foreground process knows is that its statement can't finish because a required log switch has not occurred because a checkpoint is incomplete. What the server process does not know is the checkpoint (CKPT), the database writer (DBWR) and the log writer (LGWR) background processes are involved. There is a good chance the database writer is frantically writing dirty buffers to the database (dbf) files so the LGWR can safely overwrite the associated redo in the next online redo log.
For example, if a server process issued a commit during the checkpoint, it will wait until the checkpoint is complete and the log writer has switched and can write into the next redo log. So, while the log writer background processes is probably waiting on "log file parallel write" and the database writer is burning CPU and waiting on "db file parallel write", the foreground processes are effectively hung.
This is a classic example of how a background process can impact the performance of a foreground process.
A Demonstration Of The Lie
Here's a quick demonstration of the above situation. On an existing database in my lab, I created two 4MB redo logs and dropped all the other redo logs. I started a DML intensive workload. According to the alert.log file, the redo logs where switching every couple of seconds! Take a look at this:
$ tail -f /home/oracle/base/diag/rdbms/prod30/prod30/trace/alert*logThread 1 cannot allocate new log, sequence 2365Checkpoint not complete Current log# 4 seq# 2364 mem# 0: /home/oradata/prod30/redoA1.logMon Dec 29 11:02:09 2014Thread 1 advanced to log sequence 2365 (LGWR switch) Current log# 5 seq# 2365 mem# 0: /home/oradata/prod30/redoA2.logThread 1 cannot allocate new log, sequence 2366Checkpoint not complete Current log# 5 seq# 2365 mem# 0: /home/oradata/prod30/redoA2.logThread 1 advanced to log sequence 2366 (LGWR switch) Current log# 4 seq# 2366 mem# 0: /home/oradata/prod30/redoA1.logThread 1 cannot allocate new log, sequence 2367Checkpoint not complete Current log# 4 seq# 2366 mem# 0: /home/oradata/prod30/redoA1.logThread 1 advanced to log sequence 2367 (LGWR switch) Current log# 5 seq# 2367 mem# 0: /home/oradata/prod30/redoA2.logThread 1 cannot allocate new log, sequence 2368Checkpoint not complete Current log# 5 seq# 2367 mem# 0: /home/oradata/prod30/redoA2.logMon Dec 29 11:02:20 2014
Obviously not what you want to see on a production Oracle system! (But my guess many of you have.)
Using my OSM realtime session sampler tool (rss.sql - related blog posting HERE) I sampled the log writer every half a second. (There is only one log writer background process because this is an Oracle 11g database, not an Oracle Database 12c system.) If the log writer session showed up in v$session as an active session, it would be picked up by rss.sql. Both "ON CPU" and "WAIT" states are collected. Here is a sample of the output.
It's very obvious the log writer is doing some writing. But we can't tell from the above output if the process is impacting other sessions. It would have also been very interesting to sample the database writer also, but I didn't do that. To determine if the background processes are impacting other sessions, I needed to find a foreground session that was doing some commits. I noticed that session 133, a foreground process was busy doing some DML and committing as it processed its work. Just as with the log writer background process, I sampled this foreground process once every 0.5 second. Here's a sample of the output.
Wow. The foreground process is waiting a lot for the current checkpoint to be completed! So... this means the foreground process is being effectively halted until the background processes involved with the checkpoint have finished their work.
This is a great example of how Oracle background processes can impact the performance of an Oracle foreground process.
But let's be clear. Without the background processes, performance would be even worse. Why? Because all that work done in parallel and in the background would have to be done by each foreground process AND all that work would have to be closely controlled and coordinated. And that, would be a performance nightmare!
DB Time Impact On The Foreground Process
Just for the fun of it, I wrote a script to investigate DB Time, CPU consumption, non-idle wait time and the wait time for the "log file switch wait (checkpoint incomplete)" wait event for the foreground process mentioned above (session 133). The script simply gathers some session details, sleeps for 120 seconds, again gathers some session details, calculates the differences and displays the results. You can download the script HERE. Below is the output for the foreground process, session 133.SQL> @ckpttest.sql 133Table dropped.Table created.PL/SQL procedure successfully completed.CPU_S_DELTA NIW_S_DELTA DB_TIME_S_DELTA CHECK_IMPL_WAIT_S----------- ----------- --------------- ----------------- 2.362 117.71 119.973692 112.421 row selected.
Here is a quick description of the output columns.
CPU_S_DELTA is the CPU seconds consumed by session 133, which is the time model statistic DB CPU.NIW_S_DELTA is the non-idle wait time for session 133, in seconds.DB_TIME_S_DELTA is the DB Time statistic for session 133, which is the time model statistic DB Time.CHECK_IMPL_WAIT_S is the wait time only for event "log file switch (checkpoint incomplete)" for session 133, in seconds.
Does the time fit together as we expect? The "log file switch..." wait time is part of the non-idle wait time. The DB Time total is very close to the CPU time plus the non-idle wait time. Everything seems to add up nicely.
To summarize: Oracle background processes directly impacted the database time for a foreground process.
In Conclusion...
First, for sure Oracle foreground and background processes impact each other...by design for increased performance. Sometimes on real production Oracle Database systems things get messy and work that we hoped would be done in parallel must become momentarily serialized. The log file switch example above, is an example of this.
Second, the next time someone tells you that an Oracle background process does not impact the performance of a foreground process, ask them if they have experienced a "log file switch checkpoint incomplete" situation. Pause until they say, "Yes." Then just look at them and don't say a word. After a few seconds you may see a "oh... I get it." look on their face. But if not, simply point them to this post.
Thanks for reading and enjoy your work!
Craig.
الاشتراك في:
الرسائل (Atom)