[midPoint] 3.7 Running slooooow, HHH000010 messages in the log

Tue Feb 27 23:31:26 CET 2018

Additional info.

This error appeared after click "abort" button:

2018-02-27 23:05:36,984 [] [https-openssl-apr-443-exec-6] ERROR
(com.evolveum.midpoint.web.util.MidPointProfilingServletFilter):
Encountered exception:
org.apache.catalina.connector.ClientAbortException:
org.apache.coyote.CloseNowException: Connection [0], Stream [5,013],
This stream is not writable.

Hardware configuration:
2xCPU, 8 cores total, 32GB RAM

------
DB size: 17G (innodb_buffer_pool_size = 16G).
Disks for database: RAID10. Filesystem: ext4.
/dev/md8        917G   17G  854G   2% /var/lib/mysql

------
IOSTAT:
Linux 3.10.0-514.10.2.el7.x86_64 (idm)  27.02.2018      _x86_64_       
(8 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3,85    0,00    0,36    0,71    0,00   95,07

Device:            tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
[...]
md8              76,44        34,28       270,15  205224925 1617444032
[...]
--------
java version "1.8.0_152"
CATALINA_OPTS=-Xms1024M -Xmx8192M

-------
System status (midPoint dashboard):

CPU Usage    6.4
Heap memory (used/committed/max)    704.7MB / 1.3GB / 7.1GB
Non heap memory (used/committed/max)    303.0MB / 330.1MB / -1B
Threads (live/peak/total)    58 / 63 / 635

So I think this is not HW problem.

W dniu 27.02.2018 o 22:53, Wojciech Staszewski pisze:
> Hello all!
>
> From certain time I'm facing strange slowdowns in midPoint.
> Example: Edit user, set "Valid to" date, save.
>
> The operation took..., well I gave up after 1500 seconds.
>
> Top:
>
> top - 22:51:40 up 69 days,  6:40,  3 users,  load average: 1,65, 1,48, 1,33
> Tasks: 165 total,   1 running, 164 sleeping,   0 stopped,   0 zombie
> %Cpu(s):  3,1 us,  0,2 sy,  0,0 ni, 84,9 id, 11,8 wa,  0,0 hi,  0,0 si,  0,0 st
> KiB Mem : 32941960 total, 17412992 free,  6852052 used,  8676916 buff/cache
> KiB Swap: 33554428 total, 33482736 free,    71692 used. 25445768 avail Mem
>
> Log:
>
> 2018-02-27 22:26:17,380 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:27:59,461 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:29:41,498 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:31:23,690 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:33:06,113 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:34:48,436 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:36:30,992 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:38:15,776 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:40:00,766 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:41:20,932 [] [ClusterManagerThread] ERROR (com.evolveum.midpoint.task.quartzimpl.execution.StalledTasksWatcher): Task Task(id:1494846681800-0-1, name:Cleanup, oid:00000000-0000-0000-0000-000000000005) seems to be stalled (started Tue Feb 27 22:21:14 CET 2018; progress is still 0, observed since Tue Feb 27 22:31:17 CET 2018)
> 2018-02-27 22:41:45,652 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:43:32,964 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:45:16,142 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:47:00,434 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
> 2018-02-27 22:48:45,094 [] [pool-4-thread-6] INFO (org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl): HHH000010: On release of batch it still contained JDBC statements
>
>
> Anyone know how to fix it?
>
> Thanks!
> WS
>
> _______________________________________________
> midPoint mailing list
> midPoint at lists.evolveum.com
> http://lists.evolveum.com/mailman/listinfo/midpoint