Add metrics collection to the framework #523

shreyb · 2021-09-23T18:41:59Z

This PR adds lightly-wrapped prometheus metrics collection to the code, as well as adding a cherrypy webserver to serve those metrics (and other future functions). The metrics are served by default on port 8000, at /metrics, but this is all configurable. These metrics can then be collected in plaintext either by a prometheus server, or some other metrics collection service.

It is also possible to run the decisionengine without the webserver, by passing the --no-webserver flag, or by changing the environment of the systemd unit to pass that flag into the start command.

pep8speaks · 2021-09-23T18:42:06Z

Hello @shreyb! Thanks for updating this PR. We checked the lines you've touched for PEP 8 issues, and found:

There are currently no PEP 8 issues detected in this Pull Request. Cheers! 🍻

Comment last updated at 2021-11-03 21:07:41 UTC

retzkek · 2021-09-23T18:46:11Z

@shreyb can you post an example of the currently published metrics? Just a raw scrape of /metrics.

shreyb · 2021-09-23T18:52:23Z

@shreyb can you post an example of the currently published metrics? Just a raw scrape of /metrics.

Yep - here you go:

$ de-client --metrics
# HELP de_client_status_duration_seconds Multiprocess metric
# TYPE de_client_status_duration_seconds summary
de_client_status_duration_seconds_count 0.0
de_client_status_duration_seconds_sum 0.0
# HELP de_client_print_product_duration_seconds Multiprocess metric
# TYPE de_client_print_product_duration_seconds summary
de_client_print_product_duration_seconds_count 0.0
de_client_print_product_duration_seconds_sum 0.0
# HELP de_client_metrics_duration_seconds Multiprocess metric
# TYPE de_client_metrics_duration_seconds summary
de_client_metrics_duration_seconds_count 81.0
de_client_metrics_duration_seconds_sum 0.11079557938501239
# HELP de_client_start_channel_duration_seconds Multiprocess metric
# TYPE de_client_start_channel_duration_seconds summary
de_client_start_channel_duration_seconds_count{channel_name="Nersc"} 1.0
de_client_start_channel_duration_seconds_sum{channel_name="Nersc"} 0.7267125048674643
de_client_start_channel_duration_seconds_count{channel_name="test_channel"} 1.0
de_client_start_channel_duration_seconds_sum{channel_name="test_channel"} 1.3527377960272133
# HELP de_workers_total Multiprocess metric
# TYPE de_workers_total gauge
de_workers_total{pid="2102"} 1.0
de_workers_total{pid="2126"} 0.0
# HELP de_source_run_seconds Multiprocess metric
# TYPE de_source_run_seconds summary
de_source_run_seconds_count{channel_name="test_channel",source_name="SourceNOP"} 4666.0
de_source_run_seconds_sum{channel_name="test_channel",source_name="SourceNOP"} 4.778663814533502
# HELP de_transform_run_seconds Multiprocess metric
# TYPE de_transform_run_seconds summary
de_transform_run_seconds_count{channel_name="test_channel",transform_name="TransformNOP"} 4665.0
de_transform_run_seconds_sum{channel_name="test_channel",transform_name="TransformNOP"} 79.57181591587141
# HELP de_logicengine_run_seconds Multiprocess metric
# TYPE de_logicengine_run_seconds summary
de_logicengine_run_seconds_count{channel_name="test_channel",logicengine_name="LogicEngine"} 4665.0
de_logicengine_run_seconds_sum{channel_name="test_channel",logicengine_name="LogicEngine"} 90.91386365192011
# HELP de_publisher_run_seconds Multiprocess metric
# TYPE de_publisher_run_seconds summary
de_publisher_run_seconds_count{channel_name="test_channel",publisher_name="PublisherNOP"} 4665.0
de_publisher_run_seconds_sum{channel_name="test_channel",publisher_name="PublisherNOP"} 9.050738890189677
# HELP de_source_last_acquire_timestamp_seconds Multiprocess metric
# TYPE de_source_last_acquire_timestamp_seconds gauge
de_source_last_acquire_timestamp_seconds{channel_name="test_channel",pid="2126",source_name="SourceNOP"} 1.6324228903925512e+09
# HELP de_transform_last_run_timestamp_seconds Multiprocess metric
# TYPE de_transform_last_run_timestamp_seconds gauge
de_transform_last_run_timestamp_seconds{channel_name="test_channel",pid="2126",transform_name="TransformNOP"} 1.6324228904440765e+09
# HELP de_logicengine_last_run_timestamp_seconds Multiprocess metric
# TYPE de_logicengine_last_run_timestamp_seconds gauge
de_logicengine_last_run_timestamp_seconds{channel_name="test_channel",logicengine_name="LogicEngine",pid="2126"} 1.6324228904877343e+09
# HELP de_publisher_last_run_timestamp_seconds Multiprocess metric
# TYPE de_publisher_last_run_timestamp_seconds gauge
de_publisher_last_run_timestamp_seconds{channel_name="test_channel",pid="2126",publisher_name="PublisherNOP"} 1.6324228905370376e+09
# HELP de_channel_state Multiprocess metric
# TYPE de_channel_state gauge
de_channel_state{channel_name="test_channel",pid="2126"} 3.0

retzkek · 2021-09-23T19:19:22Z

Thanks. Some or all of these duration metrics may be more interesting as histograms to keep an eye on outliers; summary only gives you average duration which is generally a less interesting metric than quantiles (median, 95th, and 99th percentile are common), which can be estimated from a histogram, including across multiple instances. Summary should also be able to provide quantiles directly, but it seems that's not implemented in the Python client yet.

de_workers_total{pid="2102"} 1.0

What's the estimated cardinality of pid over the lifetime of a DE instance? Anything else you can use that's more descriptive (and bounded)?

lgtm-com · 2021-09-23T19:34:47Z

This pull request introduces 3 alerts when merging 32d802d into a4a7938 - view on LGTM.com

new alerts:

2 for 'import *' may pollute namespace
1 for Unused import

.editorconfig

src/decisionengine/framework/taskmanager/TaskManager.py

src/decisionengine/framework/engine/DecisionEngine.py

src/decisionengine/framework/taskmanager/TaskManager.py

lgtm-com · 2021-09-23T20:08:05Z

This pull request introduces 3 alerts when merging 6651d73 into a4a7938 - view on LGTM.com

new alerts:

2 for 'import *' may pollute namespace
1 for Unused import

lgtm-com · 2021-09-23T20:49:05Z

This pull request introduces 3 alerts when merging c4d0185 into a4a7938 - view on LGTM.com

new alerts:

2 for 'import *' may pollute namespace
1 for Unused import

lgtm-com · 2021-09-24T16:09:55Z

This pull request introduces 1 alert when merging b7581fe into a4a7938 - view on LGTM.com

new alerts:

1 for Unused import

lgtm-com · 2021-10-06T16:33:41Z

This pull request introduces 1 alert when merging 79c25eb into 28919b1 - view on LGTM.com

new alerts:

1 for Unused import

lgtm-com · 2021-10-06T17:12:11Z

This pull request introduces 1 alert when merging d5fa6f4 into 28919b1 - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-13T14:13:37Z

This pull request introduces 1 alert when merging c35a45b into e95071f - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-13T18:55:04Z

This pull request introduces 1 alert when merging 930bdd6 into e95071f - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-13T19:55:15Z

This pull request introduces 1 alert when merging 4ab8fcc into e95071f - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

codecov · 2021-10-13T21:21:24Z

Codecov Report

Merging #523 (1ddf907) into master (4f920dc) will decrease coverage by 0.58%.
The diff coverage is 84.21%.

❗ Current head 1ddf907 differs from pull request most recent head 7eb622b. Consider uploading reports for the commit 7eb622b to get more accurate results

@@            Coverage Diff             @@
##           master     #523      +/-   ##
==========================================
- Coverage   95.19%   94.61%   -0.59%     
==========================================
  Files          46       46              
  Lines        2852     2934      +82     
  Branches      464      476      +12     
==========================================
+ Hits         2715     2776      +61     
- Misses        103      121      +18     
- Partials       34       37       +3

Flag	Coverage Δ
python-3.10	`94.51% <84.21%> (-0.58%)`	⬇️
python-3.6	`94.35% <84.00%> (-0.48%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
src/decisionengine/framework/util/metrics.py	`83.33% <42.85%> (-16.67%)`	⬇️
src/decisionengine/framework/engine/de_client.py	`93.22% <50.00%> (-1.52%)`	⬇️
.../decisionengine/framework/engine/DecisionEngine.py	`87.36% <82.69%> (-1.91%)`	⬇️
...ecisionengine/framework/taskmanager/TaskManager.py	`96.78% <100.00%> (+0.27%)`	⬆️
src/decisionengine/framework/dataspace/maintain.py	`99.04% <0.00%> (-0.96%)`	⬇️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4f920dc...7eb622b. Read the comment docs.

lgtm-com · 2021-10-13T21:23:42Z

This pull request introduces 1 alert when merging d1f8507 into e95071f - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-15T13:41:49Z

This pull request introduces 1 alert when merging a747ef9 into 30951a5 - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-15T15:39:17Z

This pull request introduces 1 alert when merging 465d380 into 30951a5 - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-22T20:45:16Z

This pull request introduces 1 alert when merging c5cffa6 into 814669d - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-25T15:57:57Z

This pull request introduces 1 alert when merging 1f76ac1 into 814669d - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

lgtm-com · 2021-10-25T17:48:54Z

This pull request introduces 1 alert when merging 0c69662 into 814669d - view on LGTM.com

new alerts:

1 for Module is imported with 'import' and 'import from'

mambelli · 2021-10-25T21:48:58Z

@shreyb I think the linter problem is actually whitespace in an empty line that trips the pre-commit scripts. If you enable pre-commit it should have been catching and fixing that.
We will discuss the use of pypy on Thursday. If all other tests are working I'd feel OK

shreyb · 2021-10-28T21:28:07Z

#548 fixed the Github actions issue for this PR.

jcpunk · 2021-10-29T18:41:02Z

Can you squash this down to a smaller set of commits?

shreyb · 2021-11-01T16:38:04Z

Can you squash this down to a smaller set of commits?

@jcpunk Done.

…ess mode, and added CherryPy webserver for prometheus metrics

Added a section in the global config file (decision_engine.jsonnet) to allow for configuration of webserver. Currently only the port is configurable. Added code to DecisionEngine class to read port config, or use 8000 as default. Also changed DecisionEngine.start_metrics_server to DecisionEngine.start_webserver, and added a --no-webserver option to opt out of starting the webserver (metrics are still collected though).

Added steps to allow for metrics setup and disabling in systemd unit file and environment file.

In CI, all the unit tests would pass, but then the job to run the tests would time out. This is because the CherryPy webserver was started up alongside, and never was shut down. This would cause the job to eventually time out. Passing this argument should ensure that this doesn't happen.

lgtm-com · 2021-11-03T20:25:49Z

This pull request introduces 1 alert when merging 6991d17 into 4f920dc - view on LGTM.com

new alerts:

1 for Mismatch between signature and use of an overriding method

shreyb · 2021-11-03T20:56:59Z

When I've resolved the rebase errors, I'll squash those down to one commit and re-push this branch.

Errors fixed: transform.name --> worker.name, transform timestamp should use set_to_current_time like the others, accidentally brought along a couple of old methods that were deprecated

shreyb · 2021-11-03T21:08:55Z

When I've resolved the rebase errors, I'll squash those down to one commit and re-push this branch.

Done.

shreyb · 2021-11-09T16:28:56Z

Would someone be able to take a look at this by any chance? This PR has been open for a while, and I've had to rebase twice since it's been ready for review, which, on a larger PR like this, is risky. Thanks!

jcpunk · 2021-11-09T16:42:06Z

I don't see any obvious show stoppers.

vitodb

By looking at the code an test results all seems to be good.
I' approving this PR also based on feedback provided by Pat that had a close look at this PR since the beginning.

jcpunk reviewed Sep 23, 2021

View reviewed changes

.editorconfig Outdated Show resolved Hide resolved

jcpunk reviewed Sep 23, 2021

View reviewed changes

src/decisionengine/framework/taskmanager/TaskManager.py Outdated Show resolved Hide resolved

jcpunk reviewed Sep 23, 2021

View reviewed changes

src/decisionengine/framework/engine/DecisionEngine.py Outdated Show resolved Hide resolved

jcpunk reviewed Sep 23, 2021

View reviewed changes

src/decisionengine/framework/taskmanager/TaskManager.py Outdated Show resolved Hide resolved

shreyb force-pushed the metrics_cherrypy branch from 8d09532 to ae16e2b Compare October 6, 2021 16:05

shreyb force-pushed the metrics_cherrypy branch from 13f0069 to c35a45b Compare October 13, 2021 13:53

shreyb force-pushed the metrics_cherrypy branch from d1f8507 to a747ef9 Compare October 15, 2021 13:20

shreyb force-pushed the metrics_cherrypy branch from 465d380 to ac26570 Compare October 22, 2021 19:19

shreyb mentioned this pull request Oct 25, 2021

Adding a tool to help parsing Decision Engine structured logs #544

Merged

shreyb force-pushed the metrics_cherrypy branch from 4f6d9ca to c1baf7a Compare November 1, 2021 15:58

shreyb added 16 commits November 3, 2021 19:40

Added unit tests for metrics API

e3a0461

Added metrics endpoint to RPC server, changed prometheus to multiproc…

1cc26ad

…ess mode, and added CherryPy webserver for prometheus metrics

Moved TaskManager metrics to util/prometheus.py to avoid duplicates

8b621ed

Renamed prometheus.py to metrics.py

448392b

Added metrics to record time to run Modules and DecisionEngine rpc calls

c1d8a92

Added cherrypy requirement

45f6fae

Changed metric names to match prometheus convention

5b8e03e

Changed set_to_function calls to set() calls for metrics

dbc0e00

Added check for proper metrics environment and associated unit tests

3143131

Allow for metrics disabling from systemd unit file

a897afe

Added steps to allow for metrics setup and disabling in systemd unit file and environment file.

Added __all__ global to control what is exported.

0523b01

Moved multiprocess import to metrics to clean up imports.

8a14fe4

Add no-webserver setting to all DE Test Workers

aaff5c2

Added import statement to fix MultiProcessCollector

6991d17

shreyb force-pushed the metrics_cherrypy branch from 698f03a to 6991d17 Compare November 3, 2021 20:04

Fixed rebase errors

7eb622b

Errors fixed: transform.name --> worker.name, transform timestamp should use set_to_current_time like the others, accidentally brought along a couple of old methods that were deprecated

shreyb force-pushed the metrics_cherrypy branch from 1ddf907 to 7eb622b Compare November 3, 2021 21:07

vitodb approved these changes Nov 10, 2021

View reviewed changes

mambelli merged commit 91f7a76 into HEPCloud:master Nov 11, 2021

Add metrics collection to the framework #523

Add metrics collection to the framework #523

Uh oh!

Conversation

shreyb commented Sep 23, 2021

Uh oh!

pep8speaks commented Sep 23, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Comment last updated at 2021-11-03 21:07:41 UTC

Uh oh!

retzkek commented Sep 23, 2021

Uh oh!

shreyb commented Sep 23, 2021

Uh oh!

retzkek commented Sep 23, 2021

Uh oh!

lgtm-com bot commented Sep 23, 2021

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

lgtm-com bot commented Sep 23, 2021

Uh oh!

lgtm-com bot commented Sep 23, 2021

Uh oh!

lgtm-com bot commented Sep 24, 2021

Uh oh!

lgtm-com bot commented Oct 6, 2021

Uh oh!

lgtm-com bot commented Oct 6, 2021

Uh oh!

lgtm-com bot commented Oct 13, 2021

Uh oh!

lgtm-com bot commented Oct 13, 2021

Uh oh!

lgtm-com bot commented Oct 13, 2021

Uh oh!

codecov bot commented Oct 13, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

lgtm-com bot commented Oct 13, 2021

Uh oh!

lgtm-com bot commented Oct 15, 2021

Uh oh!

lgtm-com bot commented Oct 15, 2021

Uh oh!

lgtm-com bot commented Oct 22, 2021

Uh oh!

lgtm-com bot commented Oct 25, 2021

Uh oh!

lgtm-com bot commented Oct 25, 2021

Uh oh!

mambelli commented Oct 25, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

shreyb commented Oct 28, 2021

Uh oh!

jcpunk commented Oct 29, 2021

Uh oh!

shreyb commented Nov 1, 2021

Uh oh!

lgtm-com bot commented Nov 3, 2021

Uh oh!

shreyb commented Nov 3, 2021

Uh oh!

shreyb commented Nov 3, 2021

Uh oh!

shreyb commented Nov 9, 2021

Uh oh!

jcpunk commented Nov 9, 2021

Uh oh!

vitodb left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

pep8speaks commented Sep 23, 2021 •

edited

Loading

codecov bot commented Oct 13, 2021 •

edited

Loading

mambelli commented Oct 25, 2021 •

edited

Loading