Home -> Mailing Lists -> Oracle-L -> Re: Connection spike resmgr:internal state change

Re: Connection spike resmgr:internal state change

From: Andy Sayer <andysayer_at_gmail.com>
Date: Sat, 3 Sep 2022 23:00:59 -0700
Message-ID: <CACj1VR6qA7V953bGAAynM-FSEwscS2WcCoqwgGsqJhfXFDvYZQ_at_mail.gmail.com> 








Try gv$event_histogram rather than sampled ASH.



When  we raised the SR 3 years ago we were still on 12.2. The issue still
exists, there’s been no updates as far as I know (of course we had to close
the SR because the ER had been logged).



If you are not really using resource manager, you could just unset the
resource plan (it is useful during evening and weekend maintenance but that
is when it shouldn’t matter too much). I decided to just live with the 0.1
second spikes and let Oracle fix it in their own time. As long as you have
sensible connection pools, a 0.1 second pause in all calls shouldn’t be too
noticeable to your users.



Thanks,


Andy



On Sat, Sep 3, 2022 at 10:32 PM, manikandan <pvmanikandan_at_gmail.com> wrote:



> Thanks Andy for your response.

> I do not see a pattern of active sessions waiting on this event for100ms


> every 20 minutes.

>

> INST_ID       SAMPLETIME                 EVENT


>  AVGMS              COUNT(*)


>

> 1             9/3/2022 10:25:17.698 AM   resmgr:internal state change

> 100.02025           12

>

> 5             9/3/2022 11:31:00.966 AM   resmgr:internal state change

> 100.05741025641     78

>

> 1             9/3/2022 11:55:49.627 AM   resmgr:internal state change

> 100.029766666667    30

>

> 2             9/3/2022 12:24:17.005 PM   resmgr:internal state change

> 99.0695510204082    98

>

> 5             9/3/2022 12:31:29.509 PM   resmgr:internal state change

> 100.106711711712    111

>

> 3             9/3/2022 12:59:38.087 PM   resmgr:internal state change

> 100.041923076923    13

>

>

> Looks like the ER is for 12.2

>

>

> Thanks,

>

> Mani

>

>

>

> On Sat, Sep 3, 2022 at 7:19 PM Andy Sayer <andysayer_at_gmail.com> wrote:

>

>> Hi Mani,

>>

>> That’s not just an average wait time, that’s the only wait time that gets

>> hit for this.

>>

>> I’ve raised this before with support and apparently it’s expected

>> behaviour. Every 20 minutes, every active session is required to wait 0.1

>> seconds on this event so that the system can get an accurate idea of cpu

>> load.

>>

>> After a lot of back and forth with support, I was told an Enhancement

>> Request has been logged to take a look at this but I don’t expect any

>> movement on this. The ER is 30967101 and hasn’t had movement since it

>> was raised 2 years ago.

>>

>> Maybe this thread is exactly what’s need to get eyes on it though.

>>

>> Sorry I can’t be of more help,

>> Andy

>>

>> On Sat, Sep 3, 2022 at 4:04 PM, manikandan <pvmanikandan_at_gmail.com>

>> wrote:

>>

>>> Hi,

>>>

>>>

>>>

>>> Env :- AIX P9 , Oracle RAC 19.14 (Upgraded to 19c from 12.1.0.2 a month

>>> back) – 5 nodes

>>>

>>>

>>>

>>> We are observing a moderate spike on application and during that time

>>> from ASH, we see that the sessions are waiting on event “resmgr:internal

>>> state change” for an avg of 100ms on Node 3. This behavior is happening on

>>> any one of the 5 nodes at a time.  Please let me know in which situations

>>> we see this behavior and how to get rid of it.

>>>

>>>

>>>

>>> *SAMPLETIME*


>>>

>>> *INST_ID*


>>>

>>> *EVENT*


>>>

>>> *COUNT(*)*


>>>

>>> *AVGMS*


>>>

>>> 2022-09-02 10:10:12

>>>

>>> 3

>>>

>>> resmgr:internal state change

>>>

>>> 165

>>>

>>> 100

>>>

>>>

>>>

>>> From DBRM trace

>>>

>>>

>>>

>>> *** 2022-09-02T10:07:10.062162-04:00

>>>

>>> s:   1      740002           0      31.75      0.00           0

>>>

>>> t: [0] rng=3 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [1] rng=2 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [2] rng=2 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [3] rng=3 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [4] rng=2 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [5] rng=1 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [6] rng=4 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [7] rng=6 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [8] rng=3 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [9] rng=3 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> t: [10] rng=3 rbl=0 lowt=48 uadj=12 madj=0 hid=12 dyn=[60-72]

>>>

>>> r: 51024157    20943    25970      1      0      1      0

>>>

>>> kgsksysstop: successful; Total stall time = 0 ms.

>>>

>>>

>>>

>>> *** 2022-09-02T10:12:10.761588-04:00

>>>

>>> s:   0      800992           0      35.30      0.00           0

>>>

>>>

>>>

>>> We haven’t made any changes to resource plan.

>>>

>>>

>>>

>>> SQL> sho parameter resource_manager_plan

>>>

>>>

>>>

>>> NAME                                 TYPE        VALUE


>>>

>>> ------------------------------------ -----------

>>> ------------------------------

>>>

>>> resource_manager_plan                string      DEFAULT_PLAN

>>>

>>>

>>>

>>> SQL> select name, cpu_managed from v$rsrc_plan where name =

>>> 'DEFAULT_PLAN';


>>>

>>>

>>>

>>> NAME


>>> CPU


>>>

>>>

>>> -------------------------------- ---

>>>

>>>

>>> DEFAULT_PLAN


>>>           ON

>>>

>>>

>>>

>>>

>>> SQL> select group_or_subplan, mgmt_p1, mgmt_p2, mgmt_p3, mgmt_p4,

>>> mgmt_p5, mgmt_p6, mgmt_p7, mgmt_p8, max_utilization_limit from

>>> dba_rsrc_plan_directives where plan = (select name from v$rsrc_plan where

>>> name = 'DEFAULT_PLAN');

>>>

>>>

>>>

>>> GROUP_OR_SUBPLAN                  MGMT_P1    MGMT_P2    MGMT_P3


>>> MGMT_P4    MGMT_P5    MGMT_P6    MGMT_P7    MGMT_P8


>>> MAX_UTILIZATION_LIMIT


>>>

>>>

>>> ------------------------------ ---------- ---------- ----------

>>> ---------- ---------- ---------- ---------- ----------

>>> ---------------------

>>>

>>>

>>> SYS_GROUP                              90          0          0


>>> 0          0          0          0

>>> 0

>>>

>>>

>>> OTHER_GROUPS                            9          0          0


>>> 0          0          0          0          0

>>>

>>>

>>> ORA$AUTOTASK                            1          0          0


>>> 0          0          0          0          0

>>> 90

>>>

>>>

>>>

>>> *OWNER*


>>>

>>> *WINDOW_NAME*


>>>

>>> *RESOURCE_PLAN*


>>>

>>> *REPEAT_INTERVAL*


>>>

>>> *DURATION*


>>>

>>> *WINDOW_PRIORITY*


>>>

>>> *NEXT_START_DATE*


>>>

>>> *LAST_START_DATE*


>>>

>>> *ENABLED*


>>>

>>> *ACTIVE*


>>>

>>> SYS


>>>

>>> WEEKNIGHT_WINDOW


>>>

>>> DEFAULT_MAINTENANCE_PLAN


>>>

>>> freq=daily;byday=MON,TUE,WED,THU,FRI;byhour=22;byminute=0; bysecond=0

>>>

>>> +00 08:00:00.000000

>>>

>>> LOW


>>>

>>> 4/18/2014 10:00:00.500000 PM -04:00

>>>

>>> 4/17/2014 10:00:00.698771 PM -04:00

>>>

>>> FALSE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> WEEKEND_WINDOW


>>>

>>> DEFAULT_MAINTENANCE_PLAN


>>>

>>> freq=daily;byday=SAT;byhour=0;byminute=0;bysecond=0

>>>

>>> +02 00:00:00.000000

>>>

>>> LOW


>>>

>>> 4/19/2014 12:00:00.000000 AM -04:00

>>>

>>> 4/12/2014 6:00:05.593192 AM -04:00

>>>

>>> FALSE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> MONDAY_WINDOW


>>>

>>> freq=daily;byday=MON;byhour=22;byminute=0; bysecond=0

>>>

>>> +00 04:00:00.000000

>>>

>>> LOW


>>>

>>> 9/5/2022 10:00:00.000000 PM -04:00

>>>

>>> 8/29/2022 10:00:00.002518 PM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> TUESDAY_WINDOW


>>>

>>> freq=daily;byday=TUE;byhour=22;byminute=0; bysecond=0

>>>

>>> +00 04:00:00.000000

>>>

>>> LOW


>>>

>>> 9/6/2022 10:00:00.000000 PM -04:00

>>>

>>> 8/30/2022 10:00:00.041928 PM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> WEDNESDAY_WINDOW


>>>

>>> freq=daily;byday=WED;byhour=22;byminute=0; bysecond=0

>>>

>>> +00 04:00:00.000000

>>>

>>> LOW


>>>

>>> 9/7/2022 10:00:00.000000 PM -04:00

>>>

>>> 8/31/2022 10:00:00.042308 PM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> THURSDAY_WINDOW


>>>

>>> freq=daily;byday=THU;byhour=22;byminute=0; bysecond=0

>>>

>>> +00 04:00:00.000000

>>>

>>> LOW


>>>

>>> 9/8/2022 10:00:00.000000 PM -04:00

>>>

>>> 9/1/2022 10:00:00.026817 PM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> FRIDAY_WINDOW


>>>

>>> freq=daily;byday=FRI;byhour=22;byminute=0; bysecond=0

>>>

>>> +00 04:00:00.000000

>>>

>>> LOW


>>>

>>> 9/2/2022 10:00:00.000000 PM -04:00

>>>

>>> 8/26/2022 10:00:00.000553 PM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> SATURDAY_WINDOW


>>>

>>> freq=daily;byday=SAT;byhour=6;byminute=0; bysecond=0

>>>

>>> +00 20:00:00.000000

>>>

>>> LOW


>>>

>>> 9/3/2022 6:00:00.000000 AM -04:00

>>>

>>> 8/27/2022 6:00:00.026665 AM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>> SYS


>>>

>>> SUNDAY_WINDOW


>>>

>>> freq=daily;byday=SUN;byhour=6;byminute=0; bysecond=0

>>>

>>> +00 20:00:00.000000

>>>

>>> LOW


>>>

>>> 9/4/2022 6:00:00.000000 AM -04:00

>>>

>>> 8/28/2022 6:00:00.030427 AM -04:00

>>>

>>> TRUE


>>>

>>> FALSE


>>>

>>>

>>>

>>>

>>>

>>> Thanks,

>>>

>>> Mani

>>>

>>



--
http://www.freelists.org/webpage/oracle-l


Received on Sun Sep 04 2022 - 08:00:59 CEST












Original text of this message