Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Several statsd timers record seconds rather than milliseconds #10629

Closed
mjpieters opened this issue Aug 28, 2020 · 1 comment
Closed

Several statsd timers record seconds rather than milliseconds #10629

mjpieters opened this issue Aug 28, 2020 · 1 comment
Labels
kind:bug This is a clearly a bug priority:critical Showstopper bug that should be patched immediately
Milestone
Airflow 2.0.0rc1

Comments

@mjpieters
Copy link
Contributor

Apache Airflow version: 1.10.11

What happened:

Statsd timers for 3 categories are reporting values 1000x off as the code passes seconds, rather rather than milliseconds (or a timedelta() instance) to StatsClient.timing().

What you expected to happen:

The timings should be reported in milliseconds.

How to reproduce it:

Enable the statsd client and track reporting timings for:

  • dag.loading-duration.* (emitted from models/dagbag.py)
  • dag.<dag_id>.<task_id>.duration (emitted from models/taskinstance.py)
  • dag_processing.last_duration.<filename> (emitted from utils/dag_processing.py) and it's deprecated alias dag_processing.last_runtime.*

Anything else we need to know:

This was reported before, for the dag_processing.last_* stats, at https://issues.apache.org/jira/browse/AIRFLOW-6088.
The accompanying pull request #6682, fixed 2 out of 3 of these, but only for Airflow 2.0.
@mjpieters mjpieters added the kind:bug This is a clearly a bug label Aug 28, 2020
@mjpieters mjpieters mentioned this issue Aug 28, 2020
Merged
@mjpieters mjpieters mentioned this issue Aug 28, 2020
Merged
mjpieters added a commit to mjpieters/airflow that referenced this issue Nov 21, 2020
@mjpieters
Backport pull request apache#10629 to v1-10
a31f416
@ashb ashb added this to the Airflow 2.0.0-beta4 milestone Nov 25, 2020
@ashb ashb added the priority:critical Showstopper bug that should be patched immediately label Nov 25, 2020
@ashb
Copy link
Member

ashb commented Nov 25, 2020 •
edited
Loading

I think there may be one left -- in DagBag.collect_dags

        durations = (end_dttm - start_dttm).total_seconds()
        Stats.gauge('collect_dags', durations, 1)

Oh, that's a guage.

@ashb ashb closed this as completed Nov 28, 2020
ashb added a commit to astronomer/airflow that referenced this issue Dec 5, 2020
@ashb
Don't emit first_task_scheduling_delay metric for only-once dags
7ecdcc6 
Dags with a schedule interval of None, or `@once` don't have a following
schedule, so we can't realistically calculate this metric.

Additionally, this changes the emitted metric from seconds to
milliseconds -- all timers to statsd should be in milliseconds -- this
is what Statsd and apps that consume data from there expect. See apache#10629
for more details.

This will be a "breaking" change from 1.10.14, where the metric was
back-ported to, but was (incorrectly) emitting seconds.
@ashb ashb mentioned this issue Dec 5, 2020
Merged
ashb added a commit that referenced this issue Dec 5, 2020
@ashb
Don't emit first_task_scheduling_delay metric for only-once dags (#12835
4a02e0a 
)

Dags with a schedule interval of None, or `@once` don't have a following
schedule, so we can't realistically calculate this metric.

Additionally, this changes the emitted metric from seconds to
milliseconds -- all timers to statsd should be in milliseconds -- this
is what Statsd and apps that consume data from there expect. See #10629
for more details.

This will be a "breaking" change from 1.10.14, where the metric was
back-ported to, but was (incorrectly) emitting seconds.
kaxil pushed a commit that referenced this issue Dec 7, 2020
@ashb @kaxil
Don't emit first_task_scheduling_delay metric for only-once dags (#12835
2c92b02 
)

Dags with a schedule interval of None, or `@once` don't have a following
schedule, so we can't realistically calculate this metric.

Additionally, this changes the emitted metric from seconds to
milliseconds -- all timers to statsd should be in milliseconds -- this
is what Statsd and apps that consume data from there expect. See #10629
for more details.

This will be a "breaking" change from 1.10.14, where the metric was
back-ported to, but was (incorrectly) emitting seconds.

(cherry picked from commit 4a02e0a)
kaxil pushed a commit that referenced this issue Jan 22, 2021
@mjpieters
Ensure all statsd timers use millisecond values. (#10633)
48daabc 
* Backport pull request #6682 to v1-10
* Backport pull request #10629 to v1-10
cfei18 pushed a commit to cfei18/incubator-airflow that referenced this issue Mar 5, 2021
@ashb
Don't emit first_task_scheduling_delay metric for only-once dags (apa…
9c24ca5 
…che#12835)

Dags with a schedule interval of None, or `@once` don't have a following
schedule, so we can't realistically calculate this metric.

Additionally, this changes the emitted metric from seconds to
milliseconds -- all timers to statsd should be in milliseconds -- this
is what Statsd and apps that consume data from there expect. See apache#10629
for more details.

This will be a "breaking" change from 1.10.14, where the metric was
back-ported to, but was (incorrectly) emitting seconds.

(cherry picked from commit 4a02e0a)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind:bug This is a clearly a bug priority:critical Showstopper bug that should be patched immediately
Projects
None yet
Milestone
Airflow 2.0.0rc1
Development

No branches or pull requests
3 participants
@ashb @mjpieters @potiuk