Add simple smart group profiler

[artfulrobot]

See
https://lab.civicrm.org/dev/core/-/issues/4350

Before trying this you need to:

alter table  `civicrm_group` add cache_fill_took DECIMAL(10, 2) DEFAULT NULL COMMENT "Time taken to fill cache in seconds.";

Once you've done that then when smart groups' caches are filled, it updates the civicrm_Group table with how long it took in seconds.

A warning is emitted via Civi::log() if it takes over 5s.

This PR would need a core updater step to add the above field to civicrm_group (+ xml, DAO, etc.)

Either as part of this PR or a followup, we could add a system status check thing to scan SELECT * FROM civicrm_group WHERE cache_fill_took > 5 and report the smart groups that are slow.

[civibot]

🤖 Thank you for contributing to CiviCRM! ❤️ We will need to test and review this PR. 👷

Introduction for new contributors...

• If this is your first PR, an admin will greenlight automated testing with the command ok to test or add to whitelist.
• A series of tests will automatically run. You can see the results at the bottom of this page (if there are any problems, it will include a link to see what went wrong).
• A demo site will be built where anyone can try out a version of CiviCRM that includes your changes.
• If this process needs to be repeated, an admin will issue the command test this please to rerun tests and build a new demo site.
• Before this PR can be merged, it needs to be reviewed. Please keep in mind that reviewers are volunteers, and their response time can vary from a few hours to a few weeks depending on their availability and their knowledge of this particular part of CiviCRM.
• A great way to speed up this process is to "trade reviews" with someone - find an open PR that you feel able to review, and leave a comment like "I'm reviewing this now, could you please review mine?" (include a link to yours). You don't have to wait for a response to get started (and you don't have to stop at one!) the more you review, the faster this process goes for everyone 😄
• To ensure that you are credited properly in the final release notes, please add yourself to contributor-key.yml
• For more information about contributing, see CONTRIBUTING.md.

Quick links for reviewers...

• ➡️ PR Demo site (can be rebuilt with the command test this please).
• 📖 Review standards
• 🗒️ Review template (brief or verbose)

➡️ Online demo of this PR 🔗

[eileenmcnaughton]

This is pretty interesting. I don't know whether all sites would agree on the 5s but I guess if it's just going to the log then only developers can care & that conversation can arise when they do..

@andrew-cormick-dockery @johntwyman

[andrew-cormick-dockery]

Looks like our log is going to blow out!

On a more serious note, how about not hard coding the 5s and make it a PHP constant defined in civicrm.settings.php?

[aydun]

Looks useful, but agree with not hard coding 5s.

[larssandergreen]

I like the concept and the simplicity. But it looks to me that in populateTemporaryTableWithContactsInGroups(), we could be dealing with multiple groups at once, so $took would be the time for however many groups were passed into that function.

It looks like it isn't that important (used from the API Spec Provider and from Reports), so maybe you could just scratch that part?

[artfulrobot]

@aydun @andrew-cormick-dockery Good point. It's now an optional constant CIVICRM_SLOW_SMART_GROUP_SECONDS if this is not set, then no warnings are logged.

[artfulrobot]

@larssandergreen I've removed it from populateTemporaryTableWithContactsInGroups on your suggestion because I don't have a good understanding of that process or when it's called? Seems to possibly be to do with custom searches? There's a slight wrinkle here because this function will reset the took column to NULL now. But if it's not called that much then it might not matter; most the time there will be data. And anyway, if an admin has configured CIVICRM_SLOW_SMART_GROUP_SECONDS then those would still get logged during general smart group cache refills.

Added upgrader, GenCode, @eileenmcnaughton 's constant suggestion.

[artfulrobot]

(Nb. I added the updater for 5.65 but this is possibly wrong.)

[colemanw]

(Nb. I added the updater for 5.65 but this is possibly wrong.)

Current master branch is 5.66.

[eileenmcnaughton]

Ohh populateTemporaryTableWithContactsInGroups is weird - I though that was a function on it's way out / only used for reports but apiv4 uses it - maybe @mattwire / @colemanw have pushed the trauma of their last visit to this code less deep into their brains & call recall better

[artfulrobot]

Options:

• go deep in attempt to make figures more accurate: not sure this topic is worth that level of priority, if it is not simple as you imply.
• as now: when cache recreated by that codepath we lose the 'took' stats.
• alt: teach it not to set took field w/out startTime. Means cache date is unlinked from took, but there's more likely to be took data available.

[eileenmcnaughton]

I think 2 might be OK - this has low visibility & if it is a bit experimental to start with & then gets iterated I think that is OK

[artfulrobot]

@eileenmcnaughton ok well (2) is what we have now.

I've rebased on master[sic] and changed the upgrader to FiveSixtySix

So if you're happy to go ahead it should be good to merge I think, assuming tests pass.

[artfulrobot]

not convinced the test fail is significant?

[eileenmcnaughton]

test this please jenkins

Let's try again

History

Parameters

Environment Variables

Test Result

Previous Build

Next Build

Regression

Civi\FlexMailer\ConcurrentDeliveryTest.testConcurrency with data set #5 (from Civi_FlexMailer_ConcurrentDeliveryTest__testConcurrency)

Failing for the past 1 build (Since #4418 )

Took 1.2 sec.

Stacktrace

Civi\FlexMailer\ConcurrentDeliveryTest::testConcurrency with data set #5 (array(10, 2, 3, 3), array(3, 1, 2), 10)
API tallies should match.Array
(

[History](https://test.civicrm.org/job/CiviCRM-Core-Matrix-PR/4418/BKPROF=dfl,SUITES=phpunit-core-exts,label=bknix-tmp/testReport/junit/(root)/Civi_FlexMailer_ConcurrentDeliveryTest/testConcurrency_with_data_set__5/history) [Parameters](https://test.civicrm.org/job/CiviCRM-Core-Matrix-PR/4418/BKPROF=dfl,SUITES=phpunit-core-exts,label=bknix-tmp/parameters)

Environment Variables
Test Result
Previous Build
Next Build
Regression
Civi\FlexMailer\ConcurrentDeliveryTest.testConcurrency with data set #5 (from Civi_FlexMailer_ConcurrentDeliveryTest__testConcurrency)

Failing for the past 1 build (Since #4418 )
Took 1.2 sec.
Stacktrace
Civi\FlexMailer\ConcurrentDeliveryTest::testConcurrency with data set #5 (array(10, 2, 3, 3), array(3, 1, 2), 10)
API tallies should match.Array
(

[larssandergreen]

Looks like test failures were due to the unzipping issues.
Test this please.

[larssandergreen]

I'm also in support of merging this for now, but I would support not overwriting cache_fill_took. I think maybe a note in the xml comment could make it clear that it may not be linked to the cache_date. My thought is this would make it more useful if we wanted to make a SearchDisplay out of this data in the future.

I can give it an r-run, if no one else has yet.

[artfulrobot]

Having thought more about it I agree with @larssandergreen so have moved to option 3 from my earlier comment.

Better to have old data than no data.

[artfulrobot]

@colemanw done, and rebased on master. I'll add merge-on-pass

[colemanw]

Thanks Rich!