Added fields to ACL LOG error entries for precise time logging #11477
Conversation
This file contains 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
…pdated for unique error identity.
|
I'd like to learn more about the use case and justification for this. |
roshkhatri
changed the title
|
This is a commit from AWS fyi. @oranagra I think @roshkhatri updated the commit with more information. |
|
@redis/core-team We added these fields internally to better track ACL log records. Thoughts on exposing them? |
madolson
approved these changes
Nov 16, 2022
madolson
added
state:major-decision
|
Reviewed in core meeting. Summary was that we "OK" with adding more fields, but really want to understand if they are necessary. @yossigo will take a second look to validate we aren't missing anything. |
|
Thank you so much for the update! Looking forward to @yossigo's review. |
|
Hey @yossigo, Please take a look at these changes so we can validate if we aren't leaving out anything, Thank You! |
|
Cool, let's update the docs and we can close this. We previously reviewed this in the core meeting, and were just waiting on Yossi. |
|
Sounds good. Updating the docs now. |
madolson
added
the
release-notes
madolson
added a commit
to redis/redis-doc
that referenced
this pull request
Feb 2, 2023
Updating the doc for the changes made in redis/redis#11477. Added description for the ACL LOG fields.
enjoy-binbin
added a commit
to enjoy-binbin/redis
that referenced
this pull request
Feb 3, 2023
There is a timing issue in the new ACL log test:
```
*** [err]: ACL LOG aggregates similar errors together and assigns unique entry-id to new errors in tests/unit/acl.tcl
Expected 1675382873989 < 1675382873989 (context: type eval line 15 cmd {assert {$timestamp_last_update_original < $timestamp_last_updated_after_update}} proc ::test)
```
Looking at the test code, we will check the `timestamp-last-updated` before
and after a new ACL error occurs. Actually `WRONGPASS` errors can be executed
very quickly on fast machines. For example, in the this case, the execution is
completed within one millisecond.
The error is easy to reproduce, if we reduce the number of the for loops, for
example set to 2, and using --loop and --stop. Avoid this timing issue by adding
an `after 1` before the new errors.
The test was introduced in redis#11477.
oranagra
pushed a commit
that referenced
this pull request
Feb 3, 2023
There is a timing issue in the new ACL log test:
```
*** [err]: ACL LOG aggregates similar errors together and assigns unique entry-id to new errors in tests/unit/acl.tcl
Expected 1675382873989 < 1675382873989 (context: type eval line 15 cmd {assert {$timestamp_last_update_original < $timestamp_last_updated_after_update}} proc ::test)
```
Looking at the test code, we will check the `timestamp-last-updated` before
and after a new ACL error occurs. Actually `WRONGPASS` errors can be executed
very quickly on fast machines. For example, in the this case, the execution is
completed within one millisecond.
The error is easy to reproduce, if we reduce the number of the for loops, for
example set to 2, and using --loop and --stop. Avoid this timing issue by adding
an `after 1` before the new errors.
The test was introduced in #11477.
Mixficsol
pushed a commit
to Mixficsol/redis
that referenced
this pull request
Apr 12, 2023
…#11477) Added 3 fields to the ACL LOG - adds entry_id, timestamp_created and timestamp_last_updated, which updates similar existing log error entries. The pair - entry_id, timestamp_created is a unique identifier of this entry, in case the node dies and is restarted, it can detect that if it's a new series. The primary use case of Unique id is to uniquely identify the error messages and not to detect if the server has restarted. entry-id is the sequence number of the entry (starting at 0) since the server process started. Can also be used to check if items were "lost" if they fell between periods. timestamp-created is the unix-time in ms at the time the entry was first created. timestamp-last-updated is the unix-time in ms at the time the entry was last updated Time_created gives the absolute time which better accounts for network time as compared to time since. It can also be older than 60 secs and presently there is no field that can display the original time of creation once the error entry is updated. The reason of timestamp_last_updated field is that it provides a more precise value for the “last time” an error was seen where as, presently it is only in the 60 second period. Co-authored-by: Madelyn Olson <madelyneolson@gmail.com>
Mixficsol
pushed a commit
to Mixficsol/redis
that referenced
this pull request
Apr 12, 2023
There is a timing issue in the new ACL log test:
```
*** [err]: ACL LOG aggregates similar errors together and assigns unique entry-id to new errors in tests/unit/acl.tcl
Expected 1675382873989 < 1675382873989 (context: type eval line 15 cmd {assert {$timestamp_last_update_original < $timestamp_last_updated_after_update}} proc ::test)
```
Looking at the test code, we will check the `timestamp-last-updated` before
and after a new ACL error occurs. Actually `WRONGPASS` errors can be executed
very quickly on fast machines. For example, in the this case, the execution is
completed within one millisecond.
The error is easy to reproduce, if we reduce the number of the for loops, for
example set to 2, and using --loop and --stop. Avoid this timing issue by adding
an `after 1` before the new errors.
The test was introduced in redis#11477.
enjoy-binbin
pushed a commit
to enjoy-binbin/redis
that referenced
this pull request
Jul 31, 2023
…#11477) Added 3 fields to the ACL LOG - adds entry_id, timestamp_created and timestamp_last_updated, which updates similar existing log error entries. The pair - entry_id, timestamp_created is a unique identifier of this entry, in case the node dies and is restarted, it can detect that if it's a new series. The primary use case of Unique id is to uniquely identify the error messages and not to detect if the server has restarted. entry-id is the sequence number of the entry (starting at 0) since the server process started. Can also be used to check if items were "lost" if they fell between periods. timestamp-created is the unix-time in ms at the time the entry was first created. timestamp-last-updated is the unix-time in ms at the time the entry was last updated Time_created gives the absolute time which better accounts for network time as compared to time since. It can also be older than 60 secs and presently there is no field that can display the original time of creation once the error entry is updated. The reason of timestamp_last_updated field is that it provides a more precise value for the “last time” an error was seen where as, presently it is only in the 60 second period. Co-authored-by: Madelyn Olson <madelyneolson@gmail.com>
enjoy-binbin
added a commit
to enjoy-binbin/redis
that referenced
this pull request
Jul 31, 2023
There is a timing issue in the new ACL log test:
```
*** [err]: ACL LOG aggregates similar errors together and assigns unique entry-id to new errors in tests/unit/acl.tcl
Expected 1675382873989 < 1675382873989 (context: type eval line 15 cmd {assert {$timestamp_last_update_original < $timestamp_last_updated_after_update}} proc ::test)
```
Looking at the test code, we will check the `timestamp-last-updated` before
and after a new ACL error occurs. Actually `WRONGPASS` errors can be executed
very quickly on fast machines. For example, in the this case, the execution is
completed within one millisecond.
The error is easy to reproduce, if we reduce the number of the for loops, for
example set to 2, and using --loop and --stop. Avoid this timing issue by adding
an `after 1` before the new errors.
The test was introduced in redis#11477.
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.
Added 3 fields to the ACL LOG - adds entry_id, timestamp_created and timestamp_last_updated, which updates similar existing log error entries. The pair - entry_id, timestamp_created is a unique identifier of this entry, in case the node dies and is restarted, it can detect that if it's a new series.
The primary use case of Unique id is to uniquely identify the error messages and not to detect if the server has restarted.
Time_created gives the absolute time which better accounts for network time as compared to time since. It can also be older than 60 secs and presently there is no field that can display the original time of creation once the error entry is updated.
The reason of timestamp_last_updated field is that it provides a more precise value for the “last time” an error was seen where as, presently it is only in the 60 second period.
Changes in acl.c: adds entry_id, timestamp_created and timestamp_last_updated to ACL LOG.
Changes in acl.tcl: adds test that verify that all of the additional fields are available in the reply when the ACL LOG commands and verifies that timestamp_created does not change when log entry is updated and that timestamp-last-updated is updated when entry is updated. Also checks if a new unique id is assigned to a new task.