fjmacagno opened a new issue, #72110:
URL: https://github.com/apache/airflow/issues/72110
### Under which category would you file this issue?
Airflow Core
### Apache Airflow version
3.3.1
### What happened and how to reproduce it?
When we moved from the older statsd metrics to the new ones, the values for
some metrics changed from ms to s.
AI-analysis:
With `[metrics] statsd_datadog_enabled = True`, every metric emitted via
`Stats.timer()` is
under-reported by 1000x. `Stats.timing()` metrics are unaffected, so units
become inconsistent
between metrics on the same backend.
Airflow's own `Timer` computes its duration in milliseconds, but delegates
the actual send to the
backend timer — `_shared/observability/metrics/protocols.py`:
```python
def stop(self, send: bool = True) -> None:
if self._start_time is not None:
self.duration = 1000.0 * (time.perf_counter() - self._start_time) #
Convert to milliseconds.
if send and self.real_timer:
self.real_timer.stop()
```
For the DogStatsD backend that `real_timer` is a datadogpy
`TimedContextManagerDecorator`, created
without `use_ms` — `_shared/observability/metrics/datadog_logger.py`:
```python
return Timer(self.dogstatsd.timed(stat, tags=tags_list, **kwargs)) #
timer()
```
`DogStatsd.use_ms` defaults to `False` and `get_dogstatsd_logger()` never
sets it, so
`datadog/dogstatsd/context.py` sends elapsed **seconds** under the `|ms`
type:
```python
elapsed = monotonic() - start
use_ms = self.use_ms if self.use_ms is not None else self.statsd.use_ms
elapsed = round(1000 * elapsed) if use_ms else elapsed
self.timing_func(self.metric, elapsed, self.tags, self.sample_rate)
```
The sibling `timing()` method in the same class converts correctly, which is
why only `timer()` is
affected:
```python
if isinstance(dt, datetime.timedelta):
dt = dt.total_seconds() * 1000.0
return self.dogstatsd.timing(metric=stat, value=dt, tags=tags_list)
```
### What you think should happen instead?
All stats should be in ms. In theory fixable with one change in
`get_dogstatsd_logger()`:
```python
dogstatsd = DogStatsd(**dogstatsd_kwargs, use_ms=True)
```
Im willing to submit a PR if this is the correct solution. However, i
imagine this is a breaking change that may not be desirable?
### Operating System
_No response_
### Deployment
Official Apache Airflow Helm Chart
### Apache Airflow Provider(s)
_No response_
### Versions of Apache Airflow Providers
_No response_
### Official Helm Chart version
1.22.0 (latest released)
### Kubernetes Version
_No response_
### Helm Chart configuration
_No response_
### Docker Image customizations
_No response_
### Anything else?
Some AI-generated analysis:
### Measured
Production deployment, hourly buckets, switching `statsd_datadog_enabled`
off → on:
| metric | path | before | after |
|---|---|---|---|
| `scheduler.scheduler_loop_duration.95percentile` | `timer()` | ~1100 |
**1.13** |
| `kubernetes_executor.pod_creation.avg` | `timer()` | 23.5 | **0.0240** |
| `dagrun.schedule_delay.95percentile` | `timing()` — control | 1.9–4.6e8 |
unchanged |
`pod_creation` times a single `create_namespaced_pod` API call: 23.5 ms is
plausible, 0.024 ms is
not — confirming milliseconds was the correct unit.
### How to reproduce
1. `[metrics] statsd_on = True`, `[metrics] statsd_datadog_enabled = True`.
2. Compare `scheduler.scheduler_loop_duration` against
`dagrun.schedule_delay`; the former is 1000x
below its true value.
3. Setting `statsd_datadog_enabled = False` restores the correct magnitude
for `timer()` metrics.
### Anything else
No configuration-only workaround: `use_ms` has no environment variable,
Airflow never sets it, and
`[metrics] statsd_custom_client_path` is read only by `statsd_logger.py`,
not the DogStatsD backend.
Introduced by #15132 (merged 2021-04-01), which fixed DogStatsD mode by
changing
`self.dogstatsd.timer(...)` to `self.dogstatsd.timed(...)`. `timed()`
defaults to seconds where
`timing()` takes milliseconds, so the unit regression came in with that fix
and affects every
release since.
Distinct from #10629 / #20804, which concern *callers* passing seconds into
`timing()`. One instance
of that does still exist independently of this issue:
`dag_processing.last_duration` passes
`time.monotonic()` seconds straight into `stats.timing()`, so it is 1000x
low on both backends.
### Are you willing to submit PR?
- [x] Yes I am willing to submit a PR!
### Code of Conduct
- [x] I agree to follow this project's [Code of
Conduct](https://github.com/apache/airflow/blob/main/CODE_OF_CONDUCT.md)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
