Thanks all, this is really useful information!

Since in both cases most time is lost on executing "flushes" or
"partial-flushes", I think the problem is similar to
https://jira.duraspace.org/browse/DS-3552: In AUTO mode
<https://docs.jboss.org/hibernate/orm/4.3/javadocs/org/hibernate/FlushMode.html#MANUAL>
Hibernate keeps track of all objects loaded from the database and tries to
"auto-save" them in the database before executing a new query. But the more
objects Hibernate loads into its session, the more objects it needs to
check for modification and possible interference with the new query that is
being executed. Hence the more time it takes.

*@Bill and @Ying*, would it be possible for any of you to provide an
anonymised and cleaned database that you can share with us? Make sure the
database does not contain any sensitive information. I'm sure such a
database will also be useful for other (demo and testing) purposes and the
development of DSpace 7.

*@Ying*, for the Collection and Community pages can you try setting the
context mode to READ_ONLY in the getValidity(), addPageMeta() and addBody()
methods of classes
org.dspace.app.xmlui.aspect.artifactbrowser.CollectionViewer and
org.dspace.app.xmlui.aspect.artifactbrowser.CommunityViewer. Here's an
example of how to do that:
https://github.com/DSpace/DSpace/pull/1694/files#diff-fb7249e19a6a8652860795d8fd59cd9e

*@Bill*, unfortunately the class responsible for the /community-list page
already uses the READ_ONLY mode (
https://github.com/dspace/DSpace/blob/dspace-6_x/dspace-xmlui/src/main/java/org/dspace/app/xmlui/aspect/artifactbrowser/CommunityBrowser.java#L245).
But the fact that your number of (partial-)flushes is still so high, I
wonder if there is still another place hibernate is loading so many
objects. However as a workaround, you could enable caching of that
/community-list page by setting the xmlui.community-list.cache property in
dspace.cfg to true (
https://github.com/DSpace/DSpace/blob/dspace-6_x/dspace/config/dspace.cfg#L1917
).


Best regards,
Tom

[image: logo] Tom Desair
250-B Suite 3A, Lucius Gordon Drive, West Henrietta, NY 14586
Gaston Geenslaan 14, Leuven 3001, Belgium
www.atmire.com
<http://atmire.com/website/?q=services&utm_source=emailfooter&utm_medium=email&utm_campaign=tomdesair>

2018-03-11 22:43 GMT+01:00 Kim Shepherd <k...@shepherd.nz>:

> Hi Bill and Ying, just a note to say I haven't managed to reproduce /
> investigate this problem thoroughly yet -- i keep getting sidetracked with
> other work! And I'm struggling a bit to reproduce with test data now that
> Bill is reporting the same problem with a fairly small / typical amount of
> items and bitstreams, so it's obviously not just connected to number of
> bitstreams attached to a single item.
>
> However I still have this on my radar, and if you discover anything else
> please let the list know! Once we know exactly which conditions are needed
> to reproduce this / identify where things are going wrong, exactly, we'll
> log a JIRA issue so we can get a fix in for a future DSpace version
>
> Cheers!
>
> Kim
>
> M: k...@shepherd.nz
> T: @kimshepherd
> P: +6421883635 <+64%2021%20883%20635>
> W: www.shepherd.nz <http://shepherd.nz>
>
> 0CCB D957 0C35 F5C1 497E CDCF FC4B ABA3 2A1A FAEC
>
> On 23 February 2018 at 09:33, Bill T <wile...@gmail.com> wrote:
>
>> Here is my hibernate log for /community-list (page takes about 90 seconds
>> to load);  We have about 200 communities, 1200 collections, and 64,000
>> items.  Unlike Ying, we essentially have one original bitstream per item,
>> primarily pdf files.  Redhat 7, Java 8, Tomcat 8.5, Postgresql 9.6.2;  32G
>> Ram, 8 CPU  This setup worked well with previous versions up to and
>> including 5.8
>>
>> I'm not trying to pile on, but hopefully some additional info will be
>> helpful!
>>
>>
>> 2018-02-22 13:52:05,871 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     372441 nanoseconds spent acquiring 1 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     233248 nanoseconds spent preparing 3 JDBC statements;
>>     482887 nanoseconds spent executing 1 JDBC statements;
>>     1985778 nanoseconds spent executing 2 JDBC batches;
>>     3867293 nanoseconds spent performing 3 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     29762475 nanoseconds spent executing 2 flushes (flushing a total of 2
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:52:05,873 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     0 nanoseconds spent acquiring 0 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     0 nanoseconds spent preparing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     0 nanoseconds spent performing 0 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     0 nanoseconds spent executing 0 flushes (flushing a total of 0
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:52:16,450 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     440048 nanoseconds spent acquiring 1 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     273468 nanoseconds spent preparing 3 JDBC statements;
>>     547508 nanoseconds spent executing 1 JDBC statements;
>>     1702327 nanoseconds spent executing 2 JDBC batches;
>>     3683682 nanoseconds spent performing 3 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     27298233 nanoseconds spent executing 2 flushes (flushing a total of 2
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:52:16,452 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     0 nanoseconds spent acquiring 0 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     0 nanoseconds spent preparing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     0 nanoseconds spent performing 0 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     0 nanoseconds spent executing 0 flushes (flushing a total of 0
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:52:27,121 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     429299 nanoseconds spent acquiring 1 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     236026 nanoseconds spent preparing 3 JDBC statements;
>>     561023 nanoseconds spent executing 1 JDBC statements;
>>     1029554 nanoseconds spent executing 2 JDBC batches;
>>     3446462 nanoseconds spent performing 3 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     23575938 nanoseconds spent executing 2 flushes (flushing a total of 2
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:52:27,123 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     0 nanoseconds spent acquiring 0 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     0 nanoseconds spent preparing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     0 nanoseconds spent performing 0 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     0 nanoseconds spent executing 0 flushes (flushing a total of 0
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:52:37,220 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     2570171 nanoseconds spent acquiring 1 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     27121987 nanoseconds spent preparing 2831 JDBC statements;
>>     641543786 nanoseconds spent executing 2831 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     1108158 nanoseconds spent performing 23 L2C puts;
>>     892275 nanoseconds spent performing 13 L2C hits;
>>     249809 nanoseconds spent performing 28 L2C misses;
>>     58195179 nanoseconds spent executing 2 flushes (flushing a total of
>> 10470 entities and 24994 collections);
>>     185425636 nanoseconds spent executing 17 partial-flushes (flushing a
>> total of 15132 entities and 15132 collections)
>> }
>>
>> 2018-02-22 13:52:37,226 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     0 nanoseconds spent acquiring 0 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     0 nanoseconds spent preparing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     0 nanoseconds spent performing 0 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     0 nanoseconds spent executing 0 flushes (flushing a total of 0
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> 2018-02-22 13:54:36,355 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     267649 nanoseconds spent acquiring 1 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     45162338 nanoseconds spent preparing 4812 JDBC statements;
>>     1756479486 nanoseconds spent executing 4812 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     36704624 nanoseconds spent performing 1411 L2C puts;
>>     50803773 nanoseconds spent performing 5623 L2C hits;
>>     14742351 nanoseconds spent performing 11243 L2C misses;
>>     31181919 nanoseconds spent executing 2 flushes (flushing a total of
>> 13504 entities and 25940 collections);
>>     60069213452 nanoseconds spent executing 7045 partial-flushes
>> (flushing a total of 37986752 entities and 37986752 collections)
>> }
>>
>> 2018-02-22 13:54:36,358 INFO  org.hibernate.engine.internal
>> .StatisticalLoggingSessionEventListener @ Session Metrics {
>>     0 nanoseconds spent acquiring 0 JDBC connections;
>>     0 nanoseconds spent releasing 0 JDBC connections;
>>     0 nanoseconds spent preparing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC statements;
>>     0 nanoseconds spent executing 0 JDBC batches;
>>     0 nanoseconds spent performing 0 L2C puts;
>>     0 nanoseconds spent performing 0 L2C hits;
>>     0 nanoseconds spent performing 0 L2C misses;
>>     0 nanoseconds spent executing 0 flushes (flushing a total of 0
>> entities and 0 collections);
>>     0 nanoseconds spent executing 0 partial-flushes (flushing a total of
>> 0 entities and 0 collections)
>> }
>>
>> --
>> You received this message because you are subscribed to a topic in the
>> Google Groups "DSpace Technical Support" group.
>> To unsubscribe from this topic, visit https://groups.google.com/d/to
>> pic/dspace-tech/VIofW7EwEXY/unsubscribe.
>> To unsubscribe from this group and all its topics, send an email to
>> dspace-tech+unsubscr...@googlegroups.com.
>> To post to this group, send email to dspace-tech@googlegroups.com.
>> Visit this group at https://groups.google.com/group/dspace-tech.
>> For more options, visit https://groups.google.com/d/optout.
>>
>
> --
> You received this message because you are subscribed to the Google Groups
> "DSpace Technical Support" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to dspace-tech+unsubscr...@googlegroups.com.
> To post to this group, send email to dspace-tech@googlegroups.com.
> Visit this group at https://groups.google.com/group/dspace-tech.
> For more options, visit https://groups.google.com/d/optout.
>

-- 
You received this message because you are subscribed to the Google Groups 
"DSpace Technical Support" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to dspace-tech+unsubscr...@googlegroups.com.
To post to this group, send email to dspace-tech@googlegroups.com.
Visit this group at https://groups.google.com/group/dspace-tech.
For more options, visit https://groups.google.com/d/optout.

Reply via email to