Hello,
yesterday we recognized that one of our Applications runs very slow. After we did a little bit of researching, we found out that one of our Update-Statements takes significant longer than the day before. After looking into v$sql we saw that the beginning of the performance issue was equal to the last_active_time of the statements parent.
The Problem occured between 10.01.2017 01:54 and 11.01.2017 01:13.
Since 11.01.2017 01:13 the perfomance is normal again.
Following the output of v$sql
SQL_ID CHILD_NUMBER EXECUTIONS CPU_TIME ELAPSED_TIME LAST_LOAD_TIME LAST_ACTIVE_TIME
288v0qky4d1wx 0 159037 5533687000 5583406945 2017-01-06/01:45:43 10.01.2017 01:31:41
288v0qky4d1wx 1 26592 83238359000 83269751636 2017-01-10/01:36:19 11.01.2017 01:56:45
288v0qky4d1wx 3 28456 1088167000 1092085188 2017-01-11/01:56:45 11.01.2017 09:28:19
(I leaved out child number 2 because it was a test on my local machine after the problem occured. The reason for this child was a language_mismatch)
In v$sql_shared_cursor we saw that the reason for the child creation was ROLL_INVALID_MISMATCH
Following the reason for the parent:
<ChildNode>
<ChildNumber>0</ChildNumber>
<ID>34</ID>
<reason>Rolling Invalidate Window Exceeded(2)</reason>
<size>0x0</size>
<details>already_processed</details>
</ChildNode>
<ChildNode>
<ChildNumber>0</ChildNumber>
<ID>34</ID>
<reason>Rolling Invalidate Window Exceeded(3)</reason>
<size>2x4</size>
<invalidation_window>1484008569</invalidation_window>
<ksugctm>1484008579</ksugctm>
</ChildNode>
<ChildNode>
<ChildNumber>0</ChildNumber>
<ID>34</ID>
<reason>Rolling Invalidate Window Exceeded(3)</reason>
<size>2x4</size>
<invalidation_window>1483573465</invalidation_window>
<ksugctm>1483573663</ksugctm>
</ChildNode>
<ChildNode>
<ChildNumber>0</ChildNumber>
<ID>34</ID>
<reason>Rolling Invalidate Window Exceeded(3)</reason>
<size>2x4</size>
<invalidation_window>1483264179</invalidation_window>
<ksugctm>1483264414</ksugctm>
</ChildNode>
<ChildNode>
<ChildNumber>0</ChildNumber>
<ID>34</ID>
<reason>Rolling Invalidate Window Exceeded(2)</reason>
<size>0x0</size>
<details>already_processed</details>
</ChildNode>
<ChildNode>
<ChildNumber>0</ChildNumber>
<ID>34</ID>
<reason>Rolling Invalidate Window Exceeded(3)</reason>
<size>2x4</size>
<invalidation_window>1483058147</invalidation_window>
<ksugctm>1483058310</ksugctm>
</ChildNode>
Could you please help me to evaluate the next steps for finding the problem.
Regards,
Lokkas
ROLL_INVALID_MISMATCH is rolling cursor invalidation.
In earlier releases, whenever you gathered stats on a table, every cursor using the table was marked for immediate re-optimization. That could be a massive and instant CPU drain on your system. So we changed it so that after the stats are gathered, the dependent cursors are "slowly" marked as needing reoptimization, to spread the load out. So one on your child cursors got affected by new statistics on one of the dependent objects.
Here is an excellent blog post on the topic
https://prutser.wordpress.com/2009/07/16/rolling-cursor-invalidation/