Grouper Developers Forum

["Black, Carey M." <>]

Michael,

Uh... 16 seconds would not have got my attention.


2018-10-16 13:56:04,879: [Thread-470] TRACE 
ZZZZZFoldersHook.grantPrivsToGroup(1193) -  - Elapsed=25
2018-10-16 13:56:04,882: [Thread-470] TRACE 
ZZZZZFoldersHook$asyncStemPostCommitInsert.callback(2272) -  - add group 
'AAAAAA' to group ' BBBBBB'
2018-10-16 14:13:01,151: [Thread-470] TRACE 
ZZZZZFoldersHook$asyncStemPostCommitInsert.callback(2279) -  -  add VIEW 
access for CCCCCC to group AAAAAA

        That is about 17 minutes.

And the matching code snip... (Starting at line 2272 through 2279 )
"
        LOG.trace(String.format("add group '%s' to group '%s'", 
findParentGroups.get(i), myGroups.get(i)));
        myCodeGroup.addMember(parentCodeGroup.toSubject());
} else {
        LOG.error(String.format("could not add '%s' as a member of '%s' due 
to one or both groups membershipGroup='%s', group='%s' not being found.", 
findParentGroups.get(i), myGroups.get(i), parentCodeGroup, myCodeGroup));
}
// also grant group view to the AM team below
if (parentCodeGroup != null && myCodeAM != null) {
        LOG.trace(" add VIEW access for " + myCodeAM.getDisplayExtension() + 
" to group " + parentCodeGroup.getDisplayExtension());
"

        FWIW: findParentGroups.get(i) is the "group extension value"  used in 
this line above line 2272: 
        Group parentCodeGroup = GroupFinder.findByName(rsess, 
groupsFolder.getName() + ":" + findParentGroups.get(i), false);

So the only thing between the two trace line are:
        Group.addMember(group.toSubject())
        if (parentCodeGroup != null && myCodeAM != null) {

It has to be in the " Group.addMember(...)" code.

  BTW: Group AAAAAA= a composite
             Group BBBBBB= simple group

And that one SQL statement pegs the CPU on the host and runs that 17 minutes 
of time. ( As far as I can tell.)

        And a "cross join" looks like a very ugly thing to do to any DB.
-- 
Carey Matthew 



-----Original Message-----
From: 

 
<>
 On Behalf Of Michael Douglass
Sent: Tuesday, October 16, 2018 2:37 PM
To: 

Subject: Re: [grouper-dev] Possible performance issue with HSQLDB...

I mentioned this a long time ago - I tried stepping through the entire 
call but could not find the issue.

I don't believe it's a performance issue as such with hsqldb. I tried 
the queries directly and they return almost immediately.

It happens in a number of places - I worked on developing an app using 
grouper and debugging was a pain because of these long delays

I'd be inclined to suggest moving to h2.

It will certainly look like a performance issue - the hangs are for 
about 16 seconds or so


On 10/16/18 14:00, Black, Carey M. wrote:
> Chris, (et. al.)
>
> I have a test instance that is currently still using the HSQLDB. ( I 
> know... I am going to reset the env and move to a "real DB" ... soon...)
>
> But I found that when a group is being added as a member of another group 
> this SQL takes a very long time to execute:
>
> select member0_.id as id1_24_,
>       member0_.hibernate_version_number as hibernat2_24_,
>       member0_.subject_id as subject_3_24_,
>       member0_.subject_source as subject_4_24_,
>       member0_.subject_type as subject_5_24_,
>       member0_.context_id as context_6_24_,
>       member0_.subject_identifier0 as subject_7_24_,
>       member0_.sort_string0 as sort_str8_24_,
>       member0_.sort_string1 as sort_str9_24_,
>       member0_.sort_string2 as sort_st10_24_,
>       member0_.sort_string3 as sort_st11_24_,
>       member0_.sort_string4 as sort_st12_24_,
>       member0_.search_string0 as search_13_24_,
>       member0_.search_string1 as search_14_24_,
>       member0_.search_string2 as search_15_24_,
>       member0_.search_string3 as search_16_24_,
>       member0_.search_string4 as search_17_24_,
>       member0_.name as name18_24_,
>       member0_.description as descrip19_24_
> from grouper_members member0_ cross join grouper_memberships_all_v 
> membership1_
> where membership1_.owner_group_id=? and membership1_.field_id=?
>       and membership1_.member_id=member0_.id and 
> membership1_.immediate_mship_enabled='T'
>
> Maybe this is the "performance issue" that you have seen from time to time 
> in the test scripts?
>       ( "cross join" sounds.... like a bad idea on any system of any size.)
>
> Maybe this is just a hibernate on HSQLDB issue? Maybe not?
>
> Hope that helps.
>