Transfer: fix transfer time and wait time metrics. Closes rucio#6482

Getting the started_at and transferred_at from the request
is useless, because this is the request _before_ its update
in the database. The information must be retrieved from the
transfertool message.

Also, record the transfer time without including the wait time.

lib/rucio/core/request.py

@@ -59,6 +59,13 @@
 
 METRICS = MetricManager(module=__name__)
 
+TRANSFER_TIME_BUCKETS = (
+    10, 30, 60, 5 * 60, 10 * 60, 20 * 60, 40 * 60, 60 * 60, 1.5 * 60 * 60, 3 * 60 * 60, 6 * 60 * 60,
+    12 * 60 * 60, 24 * 60 * 60, 3 * 24 * 60 * 60, 4 * 24 * 60 * 60, 5 * 24 * 60 * 60,
+    6 * 24 * 60 * 60, 7 * 24 * 60 * 60, 10 * 24 * 60 * 60, 14 * 24 * 60 * 60, 30 * 24 * 60 * 60,
+    float('inf')
+)
+
 
 class RequestSource:
     def __init__(self, rse: RseData, ranking=None, distance=None, file_path=None, scheme=None, url=None):
@@ -1395,19 +1402,12 @@ def observe(
                     record.files_done += 1
                     record.bytes_done += file_size
 
-                    transfer_time_buckets = (
-                        10, 30, 60, 5 * 60, 10 * 60, 20 * 60, 40 * 60, 60 * 60, 1.5 * 60 * 60, 3 * 60 * 60, 6 * 60 * 60,
-                        12 * 60 * 60, 24 * 60 * 60, 3 * 24 * 60 * 60, 4 * 24 * 60 * 60, 5 * 24 * 60 * 60,
-                        6 * 24 * 60 * 60, 7 * 24 * 60 * 60, 10 * 24 * 60 * 60, 14 * 24 * 60 * 60, 30 * 24 * 60 * 60,
-                        float('inf')
-                    )
-                    if submitted_at is not None:
-                        if started_at is not None:
-                            wait_time = (started_at - submitted_at).total_seconds()
-                            METRICS.timer(name='wait_time', buckets=transfer_time_buckets).observe(wait_time)
+                    if submitted_at is not None and started_at is not None:
+                        wait_time = (started_at - submitted_at).total_seconds()
+                        METRICS.timer(name='wait_time', buckets=TRANSFER_TIME_BUCKETS).observe(wait_time)
                         if transferred_at is not None:
-                            transfer_time = (transferred_at - submitted_at).total_seconds()
-                            METRICS.timer(name='transfer_time', buckets=transfer_time_buckets).observe(transfer_time)
+                            transfer_time = (transferred_at - started_at).total_seconds()
+                            METRICS.timer(name='transfer_time', buckets=TRANSFER_TIME_BUCKETS).observe(transfer_time)
                 else:
                     record.files_failed += 1
         if save_samples:

lib/rucio/core/transfer.py

@@ -561,8 +561,8 @@ def update_transfer_state(
                     state=tt_status_report.state,
                     file_size=request['bytes'],
                     submitted_at=request.get('submitted_at', None),
-                    started_at=request.get('started_at', None),
-                    transferred_at=request.get('transferred_at', None),
+                    started_at=fields_to_update.get('started_at', None),
+                    transferred_at=fields_to_update.get('transferred_at', None),
                     session=session,
                 )
             request_core.add_monitor_message(