Repository navigation
pool: fix start-time and end-time of firefly end markers - #8304
Open
ShawnMcKee wants to merge 1 commit into
Open
ShawnMcKee wants to merge 1 commit into
ShawnMcKee wants to merge 1 commit into
Conversation
Motivation:
The 'end' firefly reports the time interval of the transfer as
start-time = MoverInfoMessage#getTimestamp and end-time = start-time +
connection time. The mover info message is created when the transfer
has finished, so its timestamp is the end of the transfer, not its
start. As a result both times are too late by the duration of the
transfer: start-time is the moment the transfer ended and end-time
lies in the future when the marker is sent. The start and end markers
of the same transfer also disagree about when it started.
Observed on a pool for one HTTP-TPC pull of 50.4 s:
start marker, sent 16:23:15.710Z: start-time 16:23:15.710Z
end marker, sent 16:24:06.215Z: start-time 16:24:06.214Z
end-time 16:24:56.639Z
The transfer ran from 16:23:15.7 to 16:24:06.2.
The start-time was derived from the mover info timestamp following a
review comment on dCache#8044; the timestamp was then used as the start
itself.
Modification:
Use the mover info timestamp as end-time and derive start-time by
subtracting the connection time. The duration is unchanged.
The unit test that pinned the previous behaviour is updated, and now
also checks that end-time does not lie after the marker's
current-time.
Result:
The start-time and end-time of 'end' fireflies describe the interval
in which the transfer took place, and agree with the start-time of
the corresponding 'start' firefly. For the example above the derived
start-time is 16:23:15.789Z.
Acked-by:
Target: master, 12.1, 12.0, 11.2
Require-book: no
Require-notes: yes
Signed-off-by: Shawn McKee <smckee@umich.edu>
Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Problem
The
endfirefly reports the transfer interval one transfer duration too late.TransferLifeCycle.onEnd()builds it as:MoverInfoMessageis created when the transfer has finished, so its timestamp is the end of the transfer, not its start. The result:start-timeis the moment the transfer ended,end-timelies in the future when the marker is sent,startandendmarkers of the same transfer disagree about when it started.The duration (
end-time−start-time) is correct.Observed on an AGLT2 pool (11.2.10) for one HTTP-TPC pull of 50.4 s, same flow in both markers:
current-time)start-timeend-timeThe transfer ran from 16:23:15.7 to 16:24:06.2.
Cause
This came in with my change for a review comment on #8044, which asked for the start time to be derived from
moverInfo.getTimestamp(). I used the timestamp as the start itself. Before that the code usedInstant.now()as end and subtracted the duration. master, 12.1, 12.0 and 11.2 are affected.Fix
Keep deriving the times from the mover info timestamp, but use it as
end-timeand subtract the connection time to getstart-time. For the example above this gives astart-timeof 16:23:15.789Z, within 80 ms of thestartmarker.Testing
shouldDeriveEndMarkerTimesFromTransferEnd) and now also checks thatend-timeis not after the marker'scurrent-time. It fails on the unfixed code and passes with the fix.maven:3.9.12-eclipse-temurin-21(mvn -P code-coverage clean verify -DskipTests=false -Drun.slow.tests): 5172 tests, 0 failures, 0 errors.Note: #8303 touches neighbouring lines in
TransferLifeCycleTest; whichever is merged second will need a rebase, which I will do.Signed-off-by: Shawn McKee smckee@umich.edu
🤖 Generated with Claude Code