[midPoint] DB utilization at 200% -- Slow query Traced

[Florin. Stingaciu]

Hey Pavol,

Thanks for the response. The query time is in seconds. Meaning that each
batch of 500 deletions, takes approximately 2.5 minutes. I'm not sure if
this is due to the size of each entry, or due to the way the second
select (select
id from HT_m_audit_event) is performed or the way the temp table
HT_m_audit_event is crafted. The fact that this only happens once in a
while also indicates that certain audit records or certain days with a
large amount of audit records trigger this problem.

This last, the total clean up operation only took an hour or so. Last time
this happened, it took about 16 hours due to the same query. We're in the
process of evaluation a DB change, however I fear this is not a DB issue.
Is there anywhere in particular I could look in the DB to check if there's
something weird about the audit logs?

Thanks,
-F

On Fri, Oct 28, 2016 at 11:17 AM, Pavol Mederly <mederly at evolveum.com>
wrote:

> Hello Florin,
>
> yes, this queries are used to delete old audit log entries. These are
> deleted in batches of 500 entries - just because we didn't want to block
> midPoint by executing deletion of thousands of records in one transaction.
> But maybe something has to be tuned here.
>
> I'm not sure I understand your report. E.g. "Query_time: 158.144047" -
> what time units are used here?
>
> Best regards,
>
> Pavol Mederly
> Software developerevolveum.com
>
> On 27.10.2016 20:35, Florin. Stingaciu wrote:
>
> Hello,
>
> This is actually the second time this happened in our production
> environment. We are using a Galera mySQL cluster and are noticing 200% CPU
> utilization on this node, causing the midPoint app to only be able to
> perform reads but not writes. After some debuging, I managed to enable slow
> query logging on the Galera cluster, and consistently find that the
> following query is taking 15 seconds or longer and the same query happens
> repetedly:
>
> # Time: 161027 18:29:08
> # User at Host: midpoint[midpoint] @  [100.122.2.52]  Id: 3803614
> # Schema: midpoint_prod_live  Last_errno: 0  Killed: 0
> # Query_time: 158.144047  Lock_time: 0.000370  Rows_sent: 0
>  Rows_examined: 426520838  Rows_affected: 500
> # Bytes_sent: 13
> SET timestamp=1477592948;
> delete from m_audit_event where id in (select id from HT_m_audit_event);
> # Time: 161027 18:30:20
> # User at Host: midpoint[midpoint] @  [100.122.2.52]  Id: 3803793
> # Schema: midpoint_prod_live  Last_errno: 0  Killed: 0
> # Query_time: 68.407496  Lock_time: 0.000258  Rows_sent: 0  Rows_examined:
> 163394207  Rows_affected: 191
> # Bytes_sent: 11
> SET timestamp=1477593020;
> delete from m_audit_event where id in (select id from HT_m_audit_event);
>
> This is preventing midPoint from doing any writes at all. I tried
> restarting the service but that didn't help. I can't help to think this has
> something to do with the Clean Up Task.
>
> Any help, suggestions, or further debugging tips are highly welcome.
>
> Thanks,
> -F
>
>
> _______________________________________________
> midPoint mailing listmidPoint at lists.evolveum.comhttp://lists.evolveum.com/mailman/listinfo/midpoint
>
>
>
> _______________________________________________
> midPoint mailing list
> midPoint at lists.evolveum.com
> http://lists.evolveum.com/mailman/listinfo/midpoint
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.evolveum.com/pipermail/midpoint/attachments/20161028/400bbfc8/attachment.htm>