Bug: Error running node agent tick

[admtech]

We started SurrealDB with:

surreal start --log info --bind 0.0.0.0:8000 file:///opt/surrealdb/data/

After a while the message appears: ERROR surrealdb::api::engine::tasks: Error running node agent tick:...

However, the server remains functional and does not crash.

2024-04-26T10:06:29.509813Z  INFO surreal::env: Running 1.4.2 for linux on x86_64
2024-04-26T10:06:29.509948Z  WARN surreal::dbs: ❌🔒 IMPORTANT: Authentication is disabled. This is not recommended for production use. 🔒❌
2024-04-26T10:06:29.510061Z  INFO surrealdb_core::kvs::ds: Starting kvs store at file:///opt/surrealdb/data
2024-04-26T10:06:32.367032Z  INFO surrealdb_core::kvs::ds: Started kvs store at file:///opt/surrealdb/data
2024-04-26T10:06:32.367549Z  INFO surrealdb::net: Started web server on 0.0.0.0:8000
2024-04-26T10:09:17.715664Z ERROR surrealdb::api::engine::tasks: Error running node agent tick: Internal database error: ts is less than or equal to the latest ts

Greetings
Frank

SurrealDB version

Running 1.4.2 for linux on x86_64 (Ubuntu LTS)

[vitorTheDev]

Several other people also got this error, including me. So the bug is present on windows, linux and iOS.
In my case it was after 4 hours of "inactivity", but might have had some LQs hanging...

[og-dev]

Same error here too
1.4.2 for windows on x86_64

Any info?

[kirinse]

Same here too
1.4.2 for linux on aarch64
Maybe related with Internal database error: no versionstamp associated to this timestamp exists yet when i try SHOW CHANGES FOR TABLE media since '2024-04-27T01:23:52Z'.

[sgirones]

@mumoshu could you take a look?

[phughk]

Potentially related to #3906

[mumoshu]

We appreciate your reporting this issue to us!

In short, this isn't an error by itself. We need to make it flow into a lower log level, like debug, trace, or something like that.
This can relate to #3906, but almost certainly cannot be the cause of it.

---

FWIW, SurrealDB has an internal mapping between timestamps(ts) and commit versions(we call it "vs" and "versionstamp").

You can treat it as follows:

1. Transactions and commits are ordered by commit versions that are guaranteed to constantly increase (1, 2, 3, ... and so on).
2. We leverage the mapping between ts and vs. to enable replaying changes since a specific "timestamp."
3. The mapping is periodically updated in the background by trying to append the SurrealDB host's current system time to the mapping.

surrealdb::api::engine::tasks: Error running node agent tick: Internal database error: ts is less than or equal to the latest ts.

@admtech @vitorTheDev The "ERROR" (although it isn't a fundamental error as written earlier) means that 3. failed temporarily for various reasons.

It can happen when your operating system corrected the host's clock using NTP after the previous run of 3. succeeded, or you have multiple SurrealDB nodes connected to a single distributed KVS(TiKV, for example), and there are skews across nodes' clocks...

SurrealDB handles those "errors" gracefully so that any system clock skews don't break the correctness of CF or other SDB functionalities.

Internal database error: no versionstamp associated to this timestamp exists yet when i try SHOW CHANGES FOR TABLE media since '2024-04-27T01:23:52Z'.

@kirinse In addition to the above, this error on the SHOW statement can happen for various reasons, including you specified a timestamp that is too "latest," the ts<->vs mapping has not been covered yet, and/or node tick is stuck for reasons like high CPU pressure on the SDB node(s), etc.

All in all, this is fine. We need to make it flow into a lower log level, like debug, trace, or something like that, so that they don't confuse you anymore.