Fix timer.duration unit labels in logs (apache#61824)

Update timer.duration labels and examples to milliseconds, and fix the
OTel timing docstring to match runtime behavior.

Historical context: apache#39908 introduced milliseconds alignment with a
compatibility flag, and apache#43975 removed that flag and standardized
milliseconds everywhere.

Co-authored-by: Cursor <cursoragent@cursor.com>

Author: 2 people

airflow-core/src/airflow/jobs/scheduler_job_runner.py

@@ -1666,12 +1666,12 @@ def _run_scheduler_loop(self) -> None:
                 next_event = timers.run(blocking=False)
                 self.log.debug("Next timed event is in %f", next_event)
 
-            self.log.debug("Ran scheduling loop in %.2f seconds", timer.duration)
+            self.log.debug("Ran scheduling loop in %.2f ms", timer.duration)
             if span.is_recording():
                 span.add_event(
                     name="Ran scheduling loop",
                     attributes={
-                        "duration in seconds": timer.duration,
+                        "duration in ms": timer.duration,
                     },
                 )
 

airflow-core/src/airflow/plugins_manager.py

@@ -128,7 +128,7 @@ def __register_plugins(plugin_instances: list[AirflowPlugin], errors: dict[str,
         if not settings.LAZY_LOAD_PROVIDERS:
             __register_plugins(*_load_providers_plugins())
 
-    log.debug("Loading %d plugin(s) took %.2f seconds", len(plugins), timer.duration)
+    log.debug("Loading %d plugin(s) took %.2f ms", len(plugins), timer.duration)
     return plugins, import_errors
 
 

contributing-docs/05_pull_requests.rst

@@ -326,7 +326,7 @@ or to time but not send a metric:
     with Stats.timer() as timer:
         ...
 
-    log.info("Code took %.3f seconds", timer.duration)
+    log.info("Code took %.3f ms", timer.duration)
 
 For full docs on ``timer()`` check out `shared/observability/src/airflow_shared/observability/metrics/base_stats_logger.py`_.
 

shared/observability/src/airflow_shared/observability/metrics/otel_logger.py

@@ -274,7 +274,7 @@ def timing(
         *,
         tags: Attributes = None,
     ) -> None:
-        """OTel does not have a native timer, stored as a Gauge whose value is number of seconds elapsed."""
+        """OTel does not have a native timer, stored as a Gauge whose value is elapsed ms."""
         if self.metrics_validator.test(stat) and name_is_otel_safe(self.prefix, stat):
             if isinstance(dt, datetime.timedelta):
                 dt = dt.total_seconds() * 1000.0

task-sdk/src/airflow/sdk/io/fs.py

@@ -67,7 +67,7 @@ def _register_filesystems() -> Mapping[
                     raise ImportError(f"Filesystem {fs_module_name} does not have a get_fs method")
                 scheme_to_fs[scheme] = method
 
-    log.debug("loading filesystems from providers took %.3f seconds", timer.duration)
+    log.debug("loading filesystems from providers took %.3f ms", timer.duration)
     return scheme_to_fs
 
 

task-sdk/src/airflow/sdk/plugins_manager.py

@@ -111,7 +111,7 @@ def __register_plugins(plugin_instances: list[AirflowPlugin], errors: dict[str,
         if not settings.LAZY_LOAD_PROVIDERS:
             __register_plugins(*_load_providers_plugins())
 
-    log.debug("Loading %d plugin(s) took %.2f seconds", len(plugins), timer.duration)
+    log.debug("Loading %d plugin(s) took %.2f ms", len(plugins), timer.duration)
     return plugins, import_errors
 
 

task-sdk/src/airflow/sdk/serde/__init__.py

@@ -406,7 +406,7 @@ def _register():
                 log.debug("registering %s for stringifying", c_qualname)
                 _stringifiers[c_qualname] = module
 
-    log.debug("loading serializers took %.3f seconds", timer.duration)
+    log.debug("loading serializers took %.3f ms", timer.duration)
 
 
 @functools.cache