Skip to content

slowlog get command supports passing in -1 to get all logs.#9018

Merged
oranagra merged 3 commits into
redis:unstablefrom
enjoy-binbin:add_check_for_slowlog_get_count
Jun 14, 2021
Merged

slowlog get command supports passing in -1 to get all logs.#9018
oranagra merged 3 commits into
redis:unstablefrom
enjoy-binbin:add_check_for_slowlog_get_count

Conversation

@enjoy-binbin

@enjoy-binbin enjoy-binbin commented Jun 1, 2021

Copy link
Copy Markdown
Contributor

New:
Based on the results of the comments, this commit introduced slowlog get -1 to get all slow logs.

127.0.0.1:6379> slowlog len
(integer) 0
127.0.0.1:6379> slowlog get -1
(empty array)
127.0.0.1:6379> slowlog get -2
(error) ERR count should be greater than or equal to -1
127.0.0.1:6379> config set slowlog-log-slower-than 0
OK
127.0.0.1:6379> set a 1
OK
127.0.0.1:6379> slowlog get -1
1) 1) (integer) 1
   2) (integer) 1622739251
   3) (integer) 12
   4) 1) "set"
      2) "a"
      3) "1"
   5) "127.0.0.1:55892"
   6) ""
2) 1) (integer) 0
   2) (integer) 1622739247
   3) (integer) 6
   4) 1) "config"
      2) "set"
      3) "slowlog-log-slower-than"
      4) "0"
   5) "127.0.0.1:55892"
   6) ""
127.0.0.1:6379> slowlog help
 1) SLOWLOG <subcommand> [<arg> [value] [opt] ...]. Subcommands are:
 2) GET [<count>]
 3)     Return top <count> entries from the slowlog (default: 10).
 4)     It is also allowed to pass in -1 to get all slow logs.
 5)     Entries are made of:
 6)     id, timestamp, time in microseconds, arguments array, client IP and port,
 7)     client name
 8) LEN
 9)     Return the length of the slowlog.
10) RESET
11)     Reset the slowlog.
12) HELP
13)     Prints this help.
127.0.0.1:6379>

@oranagra Take a look for me when you have time. Check the code style and the help txt. Make sure i do it right. Thanks!
Need to be updated on the redis-doc?

--------- old comment ----------
Before: (When typing a negative count, it will traverse the whole slowlog list. When the slowlog list is huge. May cause serious consequences if the user type a wrong count.)

127.0.0.1:6379> slowlog reset
OK
127.0.0.1:6379> slowlog get -1
1) 1) (integer) 13
   2) (integer) 1622525509
   3) (integer) 25
   4) 1) "slowlog"
      2) "reset"
   5) "127.0.0.1:49392"
   6) ""
127.0.0.1:6379>
127.0.0.1:6379> slowlog get 0
(empty array)
127.0.0.1:6379>

After: (So i added a check. I could not help myself...)

127.0.0.1:6379> slowlog get -1
(error) ERR value is out of range, must be positive
127.0.0.1:6379> slowlog get 0  (0 is ok)
(empty array)

@enjoy-binbin

Copy link
Copy Markdown
Contributor Author

Also i think this comment about time may be wrong: /* Unix time at which the query was executed. */

/* This structure defines an entry inside the slow log list */
typedef struct slowlogEntry {
    robj **argv;
    int argc;
    long long id;       /* Unique entry identifier. */
    long long duration; /* Time spent by the query, in microseconds. */
    time_t time;        /* Unix time at which the query was executed. */
    sds cname;          /* Client name. */
    sds peerid;         /* Client network address. */
} slowlogEntry;

In slowlogCreateEntry, look like the entry create time. Or the query logged time?

slowlogEntry *slowlogCreateEntry(client *c, robj **argv, int argc, long long duration) {
    ....
    se->time = time(NULL);  // here
    se->duration = duration;
    se->id = server.slowlog_entry_id++;
    se->peerid = sdsnew(getClientPeerId(c));
    se->cname = c->name ? sdsnew(c->name->ptr) : sdsempty();
    return se;
}

@sundb

sundb commented Jun 1, 2021

Copy link
Copy Markdown
Collaborator

@enjoy-binbin The record time of slowlogCreateEntry is actually very close to the time when the command is run.
I think this comment is ok.

@enjoy-binbin

Copy link
Copy Markdown
Contributor Author

Yes i agree with that. Just for the record. Btw, if the command duration is long. Like is a really slow command.
The se->time = (command execute time + se->duration) ? Is that right? @sundb

@sundb

sundb commented Jun 1, 2021

Copy link
Copy Markdown
Collaborator

Read doc: https://redis.io/commands/slowlog.
The comment is correct, the time calculation should be as you say, but I'm not sure if it needs to be changed.

@oranagra

oranagra commented Jun 2, 2021

Copy link
Copy Markdown
Member

it looks like a bug, but maybe it can be considered a feature.
i.e. a negative count means to fetch the entire slowlog (which is not that big, and usually capped to some 128 records).
so instead of someone passing a value like 1000000 to fetch the entire slowlog, he can just pass -1.
i don't think it really causes harm.
however looking at the code, it's certainly looks like a bug, so maybe we wanna code it differently and preserve the behavior?
@yossigo WDYT?

regarding the comment or doc, from the perspective of the execution time record, IMHO it doesn't really matter if it's the beginning of the command or it's end. the typical use case is to see that some command took 20ms, and that it happened around 8am, i.e. see if it happened today, or yesterday, or match it to some maintainable operation, or a configuration change etc.

@enjoy-binbin

Copy link
Copy Markdown
Contributor Author

Right. Sounds like a good idea. I like it. And for the comment or doc, i just thought about it when I saw it. Not need to fix it

@madolson

madolson commented Jun 2, 2021

Copy link
Copy Markdown
Contributor

I agree, it really looks like a bug :). I would vote to make -1 a special value that means fetch the entire slowlog, and then make that clearer in the code.

@yossigo

yossigo commented Jun 2, 2021

Copy link
Copy Markdown
Collaborator

I agree with @madolson.

@enjoy-binbin enjoy-binbin force-pushed the add_check_for_slowlog_get_count branch from e528049 to a463a88 Compare June 3, 2021 16:45
@enjoy-binbin enjoy-binbin changed the title Avoid passing in a negative count in slowlog get command. slowlog get command supports passing in -1 to get all logs. Jun 3, 2021
@enjoy-binbin enjoy-binbin force-pushed the add_check_for_slowlog_get_count branch from a463a88 to 65b22ad Compare June 3, 2021 17:05
@enjoy-binbin enjoy-binbin force-pushed the add_check_for_slowlog_get_count branch from 65b22ad to 358dce4 Compare June 3, 2021 17:15
madolson
madolson previously approved these changes Jun 3, 2021

@madolson madolson left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Looks good to me, can you also submit a request here: https://github.com/redis/redis-doc for updating the documentation.

@madolson madolson added state:major-decision Requires core team consensus state:needs-doc-pr requires a PR to redis-doc repository labels Jun 3, 2021
Comment thread src/slowlog.c

@oranagra oranagra left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

thanks @enjoy-binbin .
can you please also make a PR to https://github.com/redis/redis-doc/pulls to document this.

Comment thread src/slowlog.c Outdated
@oranagra oranagra added the state:to-be-merged The PR should be merged soon, even if not yet ready, this is used so that it won't be forgotten label Jun 6, 2021
Co-authored-by: Oran Agra <oran@redislabs.com>
@enjoy-binbin

Copy link
Copy Markdown
Contributor Author

@oranagra No problem. Doc pr: redis/redis-doc#1585 I alerady made but seems to forget metion in here

@enjoy-binbin enjoy-binbin requested a review from oranagra June 6, 2021 08:21
@oranagra

oranagra commented Jun 6, 2021

Copy link
Copy Markdown
Member

@redis/core-team, we already have a majority, and this is in fact not a behavior change, but please respond if you feel documenting this behavior is wrong.

@oranagra oranagra added approval-needed Waiting for core team approval to be merged and removed state:needs-doc-pr requires a PR to redis-doc repository labels Jun 6, 2021
@enjoy-binbin

enjoy-binbin commented Jun 11, 2021

Copy link
Copy Markdown
Contributor Author

@oranagra @madolson This idea came about suddenly. What do you think we add a lazyfree about the slowlog reset. Maybe like #8258

/* Remove all the entries from the current slow log. */
void slowlogReset(void) {
    while (listLength(server.slowlog) > 0)
        listDelNode(server.slowlog,listLast(server.slowlog));
}

Sound silly, forget about that... No one would do it like me

127.0.0.1:6379> slowlog len
(integer) 2966648
127.0.0.1:6379> slowlog reset
OK
(0.78s)
127.0.0.1:6379>

@madolson

Copy link
Copy Markdown
Contributor

@enjoy-binbin Lol, lazyfree all of the things. Given that the default is 128, it's an anti-pattern to let it grown, I'm going to agree and say let's not make it lazyfree.

@oranagra oranagra merged commit 7900b48 into redis:unstable Jun 14, 2021
@enjoy-binbin enjoy-binbin deleted the add_check_for_slowlog_get_count branch June 14, 2021 13:57
JackieXie168 pushed a commit to JackieXie168/redis that referenced this pull request Sep 8, 2021
This was already the case before this commit, but it wasn't clear / intended in the code, now it does.
@oranagra oranagra added the release-notes indication that this issue needs to be mentioned in the release notes label Jan 23, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

approval-needed Waiting for core team approval to be merged release-notes indication that this issue needs to be mentioned in the release notes state:major-decision Requires core team consensus state:to-be-merged The PR should be merged soon, even if not yet ready, this is used so that it won't be forgotten

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants