We recently discovered that duplicates are affecting our processing stats. Let's update the stats collector code to output stats for the full job run and also output stats for the job run, excluding duplicates, if we can. This will give us the real processing speeds of all donations that could be processed and remove the guesswork involved in discounting duplicates from the current stats.
Description
Details
Related Objects
Event Timeline
@Ejegg's patch to show us the total processed, excluding duplicates, is here https://phabricator.wikimedia.org/T323273
Hi @jgleeson, I was just thinking about padding out the run time of the queue consumer and realized that your stats collector will also want to discount the time waiting for new messages if we do that.
Change 861495 had a related patch set uploaded (by Jgleeson; author: Jgleeson):
[wikimedia/fundraising/crm@master] Add new 'donations_total_messages_import_time' metric
How to test:
- pull the patch
- submit a couple of donations locally
- run the queue consumer docker-compose exec -w "/srv/civi-sites/wmff/drupal" civicrm drush -v qc
- take a look at the Prometheus output docker-compose exec civicrm sh -c "cat /srv/civi-sites/wmff/drupal/sites/default/files/prometheus/*"
you should see stats that look something like the below:
civicrm_import_create_contact_average_process_time 0.77849090099335 civicrm_import_message_contribution_insert_average_process_time 0.52667093276978 civicrm_import_message_location_update_average_process_time 0.16520845890045 civicrm_import_update_contact_civi_api_average_process_time 0.5302951335907 civicrm_import_verify_and_stage_average_process_time 0.036674022674561 civicrm_import_wmf_civicrm_contribution_message_import_average_process_time 1.349417090416 contribution_tracking_count 22 contribution_tracking_processing_rate{period="batch"} 0.6556830406189 contribution_tracking_processing_rate{period="1s"} 33.552797063707 contribution_tracking_processing_rate{period="5s"} 167.76398531853 contribution_tracking_processing_rate{period="10s"} 335.52797063707 contribution_tracking_processing_rate{period="30s"} 1006.5839119112 adyen_message_age 28.5 overall_message_age 28.5 donations_average_enqueued_age{gateway="adyen"} 28.5 donations_average_enqueued_age{gateway="all"} 28.5 donations_average_transaction_age{gateway="adyen"} 28.5 donations_average_transaction_age{gateway="all"} 28.5 donations_count{gateway="adyen"} 2 donations_count{gateway="all"} 2 donations_processing_rate{period="batch"} 3.2784261703491 donations_processing_rate{period="1s"} 0.61004881491262 donations_processing_rate{period="5s"} 3.0502440745631 donations_processing_rate{period="10s"} 6.1004881491262 donations_processing_rate{period="30s"} 18.301464447379 donations_total_messages_dequeued 2 donations_total_messages_import_time 2.7028021812439 adyen_donations 2 total_donations 2
The new stat is called donations_total_messages_import_time which is the new and improved version of donations_processing_rate{period="batch"}
The new stat is called donations_total_messages_import_time which is the new and improved version of donations_processing_rate{period="batch"}
Looks like it's a sum of all the time spent processing, so to get the equivalent rate we'd divide by donations_count{gateway="all"} , right?
Change 861500 had a related patch set uploaded (by Ejegg; author: Jgleeson):
[wikimedia/fundraising/crm@master] Add new 'donations_total_messages_import_time' metric
Change 861500 abandoned by Ejegg:
[wikimedia/fundraising/crm@master] Add new 'donations_total_messages_import_time' metric
Reason:
Change 861495 merged by jenkins-bot:
[wikimedia/fundraising/crm@master] Add new 'donations_total_messages_import_time' metric
Change 861500 restored by Ejegg:
[wikimedia/fundraising/crm@master] Add new 'donations_total_messages_import_time' metric
Change 861500 merged by jenkins-bot:
[wikimedia/fundraising/crm@master] Reuse existing timer for new import stat