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.

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

Fix several problems with the calculation of working time per client event #7511

Merged
merged 1 commit into from
Feb 27, 2024

Conversation

SpecLad
Copy link
Contributor

@SpecLad SpecLad commented Feb 23, 2024

Motivation and context

The first problem is that in the following case, the algorithm would accrue more working time than was actually spent:

          A
    |-----------|
---------+------------+------> time
         B            C

A, B and C are events. Let's say that Te(A) is the timestamp of the end of A, while T(B) and T(C) are the timestamps of B and C, respectively.

The current code in ClientEventsSerializer.to_internal_value adjusts last_timestamp after processing every event. After A is processed, last_timestamp is set to Te(A). After B is processed, last_timestamp goes backwards to T(B). So when the algorithm calculates the working time for C, it gets T(C) - T(B), when the correct answer is T(C) - Te(A). The span from T(B) to Te(A) gets counted twice.

Fix this by rewriting the algorithm, so that last_timestamp (now renamed previous_end_timestamp) can only go forwards.


The second problem is that the algorithm is unable to calculate the working time for the first event in each batch that the client sends. This is because to calculate working time for an event, you need the timestamp/duration of the previous event, and this information is unavailable for the first event in the batch.

Fix this by resending the most recently sent event along with each batch, and using it to initialize the algorithm.


In addition, sort the incoming event array by timestamp. I don't think this matters much in practice, since the UI should be accumulating them in chronological order anyway, but if in some obscure case it sends them out of order, this should help.

How has this been tested?

I added unit tests to test the algorithm. I also manually tested the UI changes to make sure that the previous event is actually sent.

Checklist

  • I submit my changes into the develop branch
  • I have created a changelog fragment
  • [ ] I have updated the documentation accordingly
  • I have added tests to cover my changes
  • [ ] I have linked related issues (see GitHub docs)
  • I have increased versions of npm packages if it is necessary
    (cvat-canvas,
    cvat-core,
    cvat-data and
    cvat-ui)

License

  • I submit my code changes under the same MIT License that covers the project.
    Feel free to contact the maintainers if that's a concern.

@SpecLad SpecLad marked this pull request as ready for review February 23, 2024 11:20
Copy link

codecov bot commented Feb 23, 2024

Codecov Report

Merging #7511 (a7c9479) into develop (7f92660) will increase coverage by 0.00%.
Report is 1 commits behind head on develop.
The diff coverage is 80.95%.

Additional details and impacted files
@@           Coverage Diff            @@
##           develop    #7511   +/-   ##
========================================
  Coverage    83.52%   83.52%           
========================================
  Files          372      372           
  Lines        39666    39661    -5     
  Branches      3718     3724    +6     
========================================
- Hits         33130    33128    -2     
+ Misses        6536     6533    -3     
Components Coverage Δ
cvat-ui 79.41% <80.41%> (+0.01%) ⬆️
cvat-server 87.31% <78.94%> (-0.01%) ⬇️

@bsekachev
Copy link
Member

bsekachev commented Feb 26, 2024

          A
    |-----------|
---------+------------+------> time
         B            C

In your example, actually, I am not sure how event A is appended into events collection before event B, because continuing events are added only when .close() method is called (in Te(A) timestamp in this example)

UPD: When sorting by timestamp added, on server side, it makes sense

timestamp = serializers.DateTimeField()
_TIME_THRESHOLD = datetime.timedelta(seconds=100)
_WORKING_TIME_RESOLUTION = datetime.timedelta(milliseconds=1)
_COLLAPSED_EVENT_SCOPES = frozenset(("change:frame",))

@classmethod
def _end_timestamp(cls, event: dict) -> datetime.datetime:
if event["scope"] in cls._COLLAPSED_EVENT_SCOPES:
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do you consider duration only for events from COLLAPSED_EVENT_SCOPES?
For example if the last event, sent in the previous request was a draw event with duration 30 seconds, we probably need the event timestamp + 30 seconds as prev end timestamp

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just kept the original logic as it was in this case. I didn't want to change the behavior where is wasn't related to the specific problems I was fixing.

end_timestamp = self._end_timestamp(event)
if end_timestamp > previous_end_timestamp:
working_time += end_timestamp - previous_end_timestamp
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Potential hack to increase working time with huge value in duration
In current code for change:frame event, but considering my comment above - in all events

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But as I see, the problem existed in the previous implementation also

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's no "hack-proof" way to implement something like this. There's no way to verify the data that the client is sending.

@bsekachev
Copy link
Member

I feel like implementation would seem easier if we consider only:

  1. start timestamp for the oldest event as a default value for default value previous_end_timestamp
  2. only end timestamps for all other events
  3. sort data not by timestamp, but by timestamp + duration

I may be wrong

@SpecLad
Copy link
Contributor Author

SpecLad commented Feb 26, 2024

In your example, actually, I am not sure how event A is appended into events collection before event B, because continuing events are added only when .close() method is called (in Te(A) timestamp in this example)

I don't know exactly how this happened, but I did observe it happening in a real event trace. Note that A in this example was not really a continuing event, but a compressed sequence of change:frame events.

I didn't really examine how the UI records such events, so there might be another bug there, but I figured I might as well rewrite the code to handle this case robustly.

@bsekachev
Copy link
Member

bsekachev commented Feb 26, 2024

I don't know exactly how this happened, but I did observe it happening in a real event trace. Note that A in this example was not really a continuing event, but a compressed sequence of change:frame events.

Yep, I looked. For change:frame that handled additionally inside the logger by ignore rules, it is a possible case.

@SpecLad
Copy link
Contributor Author

SpecLad commented Feb 26, 2024

I feel like implementation would seem easier if we consider only:

  1. start timestamp for the oldest event as a default value for default value previous_end_timestamp
  2. only end timestamps for all other events
  3. sort data not by timestamp, but by timestamp + duration

I may be wrong

This would be easier, but if you ignore start timestamps, that would mean that some events would no longer accrue working time, where they do so now:

                     B
       A         |--------|
-------+------------------------

If Ts(B) - T(A) < _TIME_THRESHOLD, but Te(B) - T(A) > _TIME_THRESHOLD, then in the current implementation, B would accrue working time, but in your proposal, it wouldn't. I think the current implementation is preferable in this case.

@bsekachev
Copy link
Member

That is true, just _TIME_THRESHOLD is too small in this case. In general it may be something about 5 minutes.
I do not think we have events that take more time to finish.

But it was an idea requiring some experiments, not proposal for current patch.

@SpecLad
Copy link
Contributor Author

SpecLad commented Feb 26, 2024

Hmm, now that I think about it, I probably shouldn't have added sorting at all. It's not necessary to solve either one of the issues I was trying to solve, and it could cause other issues by itself, because it makes it so that the last event sent by the UI is not necessarily the last event processed by the server.

I think I'm going to remove it and just let the UI determine the order that the events are processed in. Any bugs in that can be fixed on the client side.

…event

The first problem is that in the following case, the algorithm would accrue more
working time than was actually spent:

              A
        |-----------|
    ---------+------------+------> time
             B            C

A, B and C are events. Let's say that Te(A) is the timestamp of the end of A,
while T(B) and T(C) are the timestamps of B and C, respectively.

The current code in `ClientEventsSerializer.to_internal_value` adjusts
`last_timestamp` after processing every event. After A is processed,
`last_timestamp` is set to Te(A). After B is processed, `last_timestamp`
goes _backwards_ to T(B). So when the algorithm calculates the working time
for C, it gets T(C) - T(B), when the correct answer is T(C) - Te(A). The
span from T(B) to Te(A) gets counted twice.

Fix this by rewriting the algorithm, so that `last_timestamp` (now renamed
`previous_end_timestamp`) can only go forwards.

The second problem is that the algorithm is unable to calculate the working
time for the first event in each batch that the client sends. This is
because to calculate working time for an event, you need the
timestamp/duration of the previous event, and this information is unavailable
for the first event in the batch.

Fix this by resending the most recently sent event along with each batch,
and using it to initialize the algorithm.
@SpecLad SpecLad merged commit ae9f474 into cvat-ai:develop Feb 27, 2024
34 checks passed
@SpecLad SpecLad deleted the better-timekeeping branch February 27, 2024 17:48
@cvat-bot cvat-bot bot mentioned this pull request Mar 5, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants