Gap of Negative Duration could NOT be Fixed - AW Server stuck in loop without exiting

[TheFibonacciEffect]

• I am on the latest ActivityWatch version.
• I have searched the issues of this repo and believe that this is not a duplicate.

• OS name and version: Arch Linux x86_64
• ActivityWatch version: v0.13.2

Describe the bug

Within one specific week I am getting:

 2025-01-07 06:06:55 [WARNING]: Gap was of negative duration but could be safely merged (-165.163s). This message will only show once per batch.  (aw_transform.flood:46)
 2025-01-07 06:06:55 [WARNING]: Gap was of negative duration and could NOT be safely merged (-330.409s). This warning will only show once per batch.  (aw_transform.flood:52)

the query will run out of time and the banner
AxiosError: timeout of 90000ms exceeded. See dev console (F12) and/or server logs for more info.
is displayed at the top of the webpage. However the activitywatch server will still continue to use 100% of one CPU core until manually stopped.

To Reproduce

I start the server

The server is running

I can change to the previous week, no problem

Note the cpu load on the right, the spike occurs when I change the week, but its okay, because the calculation is finished after some time.
Now if I change to the week before that the CPU load does not decrease

At some time a timeout message is displayed and a warning in the logs

But even though the request is supposed to time out, the CPU usage stays at 100%

Pressing Ctrl C does not do anything

But sending SIGTERM works

Expected behavior

Just seeing the stats of that week

Documentation

Logs:
aw-log-bug.log

Additional context

Maybe related to #239

[github-actions]

Hi there!
As you're new to this repo, please make sure you've used an appropriate issue template and searched for duplicates (it helps us focus on actual development!). We'd also like to suggest that you read our contribution guidelines and our code of conduct.
Thanks a bunch for opening your first issue! 🙏

[TheFibonacciEffect]

I will keep looking for more issues that are relevant to this issue to see if something fixes this.

[TheFibonacciEffect]

In Issue #907 someone also got the same "gap of negative duration could NOT be fixed" message, but then the aw server crashed, mine does not seem to crash. That had to do with some event missing the "title" key.
However in mine there is also a week that can not be viewed. So it propably has to do with some bad event.

[TheFibonacciEffect]

I think this is the line where the logger displayes the negative duration: https://github.com/ActivityWatch/aw-core/blob/6a58ec59c16c57933fce7bad4453449168c83ebd/aw_transform/flood.py#L53

[0xbrayo]

Does this also happen using aw-server-rust?

[TheFibonacciEffect]

@0xbrayo I think its the default activity watch server. I will try with the rust one later.

[0xbrayo]

Please do, I'll try to investigate what might be causing but it's hard without being able to reproduce it.

[TheFibonacciEffect]

@0xbrayo As far as I can tell the issue does not occur in aw-server-rust : )
I cloned the repo, built the project, ran it in debugging mode using cargo and tested it by stepping through the last weeks.

[TheFibonacciEffect]

Left is the default aw-server, right is the aw-server-rust

[0xbrayo]

Left is the default aw-server, right is the aw-server-rust

Implies that the bug is somehow related to the implementation in the default python server. Check the logs for the rust server and see if there's any issues there about Negative duration

[TheFibonacciEffect]

Yes, it is mentioned multiple times in the logs

[2025-01-13 10:53:23][INFO][rocket_cors::_]: Verifying origin: http://127.0.0.1:5666
[2025-01-13 10:53:23][INFO][rocket_cors::_]: Origin has an exact match
[2025-01-13 10:53:23][INFO][rocket::server]: POST /api/0/query/ application/json:
[2025-01-13 10:53:23][INFO][rocket::server::_]: Matched: (query) POST /api/0/query/ application/json
[2025-01-13 10:53:23][WARN][aw_transform::flood]: Gap was of negative duration (-PT1501.606Ss), but could be safely merged. This error will only show once per batch.
[2025-01-13 10:53:24][INFO][rocket::server::_]: Outcome: Success(200 OK)
[2025-01-13 10:53:24][DEBUG][rocket::server]: sending response: Response {
    status: 200,
    version: HTTP/1.1,
    headers: {
        "content-type": "application/json",
        "server": "Rocket",
        "x-frame-options": "SAMEORIGIN",
        "x-content-type-options": "nosniff",
        "permissions-policy": "interest-cohort=()",
        "access-control-allow-origin": "http://127.0.0.1:5666",
        "content-length": "1631",
    },
    body: Body(
        Streaming,
    ),
}
[2025-01-13 10:53:24][INFO][rocket::server::_]: Response succeeded.

however there it seems like everything could be safetly merged.

[TheFibonacciEffect]

Im migrating to aw-server-rust now, I think that solves the issue for me.

[TheFibonacciEffect]

So I dont know if I should close the issue with that, or if it is kept open. As far as I understand activity watch wants to switch to the rust server anyways at some point.

[0xbrayo]

Keep it open. Might be useful if somebody else has the same issue. We'll archive the repo if we finally ditch the python server.

…

On Thu, 16 Jan 2025, 00:01 Caspar, ***@***.***> wrote: So I dont know if I should close the issue with that, or if it is kept open. As far as I understand activity watch wants to switch to the rust server anyways at some point. — Reply to this email directly, view it on GitHub <#1125 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AO6ENNIHDGXZOZ2Y4ZD2G3L2K3EA5AVCNFSM6AAAAABUW66GUSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDKOJTHEZDKOBQGM> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[TheFibonacciEffect]

I am somehow still getting the error, despite having now switched to aw-server-rust when making a query on that same week:

[2025-01-17 08:43:48][WARN][aw_transform::flood]: Gap was of negative duration (-PT165.163Ss), but could be safely merged. This error will only show once per batch.
[2025-01-17 08:43:48][WARN][aw_transform::flood]: Gap was of negative duration and could NOT be safely merged (-PT330.409Ss). This warning will only show once per batch.
[2025-01-17 08:43:49][ERROR][panic]: thread 'rocket-worker-thread' panicked at 'called `Result::unwrap()` on an `Err` value: RuntimeError(BacktrackLimitExceeded)': aw-transform/src/classify.rs:55
   0: <unknown>
   1: <unknown>
...

An improvement is that the server does not keep running after crashing.

Maybe it is possible that the rust server used on the 0.13.2-1 version of activity watch is not the newest version and that the aw-server-rust repo contains a fix to this issue that is not checked out here 🤔 . I will investigate further.

EDIT: No the commits that are checked out in these two repos are the same.

[TheFibonacciEffect]

By the way, is there any way to restart the activitywatch server after it crashed? Running aw-qt & disown -a still seems to close activitywatch when I close the terminal window?

[TheFibonacciEffect]

I just double checked, yes, the aw-server-rust when checked out from the github repo, does indeed work without problems.
This also still works when importing my own settings.

[0xbrayo]

By the way, is there any way to restart the activitywatch server after it crashed? Running aw-qt & disown -a still seems to close activitywatch when I close the terminal window?

I don't use aw-qt much. But since you are on linux you can set up a systemd service to run aw-server-rust with the restart=always option true. Chatgpt or Claude can help you figure it out.

I just double checked, yes, the aw-server-rust when checked out from the github repo, does indeed work without problems.
This also still works when importing my own settings.

The latest version of the aw-server-rust does not have the same issue?

[TheFibonacciEffect]

I just double checked, yes, the aw-server-rust when checked out from the github repo, does indeed work without problems.
This also still works when importing my own settings.

The latest version of the aw-server-rust does not have the same issue?

It does not have the issue when I start it using cargo from where I cloned the repo, however the issue does occur when I start activitywatch with aw-qt or when it is started automaticially when I log in. I am using the acvititywatch-bin package for arch linux. I will try to build activitywatch from this repo from source and see if that solves it. (possibly only after the exam phase which ends in 2 weeks)

[0xbrayo]

Oh cool. Though building from source is not that difficult, just run `cargo build --release` and use the binary at ./target/release/aw-server.

…

On Fri, 17 Jan 2025, 11:32 Caspar, ***@***.***> wrote: I just double checked, yes, the aw-server-rust when checked out from the github repo, does indeed work without problems. This also still works when importing my own settings. The latest version of the aw-server-rust does not have the same issue? It does not have the issue when I start it using cargo from where I cloned the repo, however the issue does occur when I start activitywatch with aw-qt or when it is started automaticially when I log in. I am using the acvititywatch-bin package for arch linux. I will try to build activitywatch from this repo from source and see if that solves it. (possibly only after the exam phase which ends in 2 weeks) — Reply to this email directly, view it on GitHub <#1125 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AO6ENNJ7J66JW3BNCUZZML32LC5ZHAVCNFSM6AAAAABUW66GUSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDKOJXGY4TINJWGU> . You are receiving this because you were mentioned.Message ID: ***@***.***>