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

[BUG] ft.aggregate slowdown with high frequency updates #4508

Open
tommey opened this issue Mar 7, 2024 · 3 comments
Open

[BUG] ft.aggregate slowdown with high frequency updates #4508

tommey opened this issue Mar 7, 2024 · 3 comments
Assignees
Labels

Comments

@tommey
Copy link

tommey commented Mar 7, 2024

Describe the bug
Our use-case is aggregation of origin-edge stream viewer counts, small amount of documents changing by the second. Even by setting all NO* flags on the schema and NOINDEX on all fields, FT.AGGREGATE is slowing down, in real world use our HTTP service starts with a response time of 60ms, then it slows down by 100ms/hour. We have even seen that it doesn't stop at the 500ms TIMEOUT, it was stopping there for around 10 minutes, but then slowed down further, after a day we were at 2 seconds of response time, the HTTP service is only executing the aggregate command and returns with the result.

To Reproduce
Copy-paste the following bash script and run it on a docker enabled host with access to docker hub.

#!/bin/bash
#
# Testing if RediSearch ft.aggregate slows down over time due to high frequency updates.
#
# This script:
# - executed on host starts a redis-stack-server container with this script as the command
# - executed in the redis-stack-server container:
#   - restarts the redis-stack-server
#   - generates 20k random HSET commands list
#   - creates the index for testing
#   - runs the pipeline once
#   - runs the aggregation a few times for baseline timing measurement
#   - runs the pipeline numerous times
#   - runs the aggregation a few times for slowdown timing measurement
#
# You can step into the container while the test is running to check info/ft.info idx:
# $ docker exec -it $(docker ps | grep "redis/redis-stack-server:7.2.0-v9" | head -1 | cut -d' ' -f1) redis-cli

# Test documents have a "t" text/tag content and a "c" count field
# - example: viewer counts on an origin stream reported via edge servers
#   - testing with 1000 origin streams, 20000 edge servers, random counts
FT_CREATE="ft.create idx on hash prefix 1 k schema t tag c numeric"

# We want to aggregate by "t" and sum "c"
# - example: total viewer counts of an origin stream
#   - expected output is 1 + 1000 * 4 lines (t, c + their values)
#   - expected response time under 50ms, stable, regardless of updates and time elapsed
FT_AGGREGATE="ft.aggregate idx * groupby 1 @t reduce sum 1 @c as count"
# Our only goal is this aggregation, we don't need any other features,
# we can drop all features that are not needed for this sole purpose.
aggregate() {
    { time echo "$FT_AGGREGATE" | redis-cli > /dev/null 2>&1; } 2>&1 | grep real | cut -c6-
}

if [ ! -f "/.dockerenv" ]; then
    echo "Start redis-stack-server with docker"
    docker run --rm -it -v $(pwd):/app -w /app redis/redis-stack-server:7.2.0-v9 bash $(basename "$0")
    exit 0
fi

echo "Start redis-server"
redis-stack-server &
sleep 1

echo "Creating 20k HSET commands (./1000)"
for i in $(seq 1 20000); do
    t=$((i%1000))
    echo "HSET k$i t t$t c $i" 1>&2
    ((i%1000==0)) && echo -n "."
done 2> pipeline

echo
echo "Creating index"
echo "$FT_CREATE" | redis-cli

echo
echo "Setting 20k keys"
cat pipeline | redis-cli --pipe

echo
echo -n "Running first aggregation: "
aggregate

echo
echo "Updating all keys 10k times (aggregate after 1M HSET-s)"
for i in $(seq 1 10000); do
    cat pipeline | redis-cli --pipe > /dev/null 2>&1
    ((i%50==0)) && {
        echo -n "Running aggregation after $((i/50))M updates: "
        aggregate
    }
done

As you can read from the script comments, it will create 20k hashmaps with 1k variation of the groupby field and random values for the aggregated numeric count; then it will run it as pipeline, run the aggregation and show the first timing, then it will start a cycle of 10k pipeline runs, running the aggregate command every 50th run (after 1M key updates) and shows a clear sign of increasing response time.

Sample:
Running aggregation after 1M updates: 0m0.046s
Running aggregation after 2M updates: 0m0.033s
Running aggregation after 3M updates: 0m0.046s
Running aggregation after 4M updates: 0m0.054s
Running aggregation after 5M updates: 0m0.079s

Expected behavior
The aggregation should have a stable response time below 50ms for 20k keys indexed, regardless the update frequency.

Screenshots
The service is called once a minute, when it reaches above 300ms we recreate the index, because we have not found any way we could make the aggregation stable.

Screenshot 2024-03-07 at 08 12 19

On the left side you can see that it was progressing upwards to 500ms, then workaround with the index recreation was released, then depending on actual traffic recreations happen sooner or later.

Environment (please complete the following information):

  • OS: Ubuntu 22.04 LTS, 64bit
  • CPU model: not relevant
  • Version/branch: redis-stack-server 7.2.0-v8 (2.8.11 RediSearch) in production, 7.2.0-v9 (2.8.12 RediSearch) in docker testing

Additional context
We have tried changing the FORK_GC configuration variables, changed MAXDOCTABLESIZE (1 makes it much worse, 100M behaves the same as the default 1M), after adding NOINDEX the GC wasn't collecting any bytes, therefore tried with NOGC then too, with no affect, as expected. Tried TAG SORTABLE, DIALECT 1-2-3-4, nothing helps.

Before adding NOINDEX num_records was increasing to much more than it should be, that could be offset by having the GC run every second, then load testing with continuous updates like the script above does eventually it jumps up to BIGINT and keeps increasing.

FT.EXPLAIN only shows wildcard, so no info from there.
FT.PROFILE shows that the result aggregation slows down on the indexer type only, as max_doc_id is increasing.

Usually a redis command is in the sub-millisecond territory, now due to the single threaded nature of redis we see that this aggregation blocks all other commands; the normal 20-30ms response time we have seen from the above testing would be acceptable, but blocking all other commands for hundreds of milliseconds is an issue, we might need to move this workload to a separate cluster to workaround this blocking it causes.

The bypass of the 500ms TIMEOUT setting is also something that should be addressed, the above test script does reproduce that too, sample:
Running aggregation after 45M updates: 0m0.503s
Running aggregation after 46M updates: 0m0.513s
Running aggregation after 47M updates: 0m0.519s
Running aggregation after 48M updates: 0m0.533s
Running aggregation after 49M updates: 0m0.561s
...
Running aggregation after 60M updates: 0m0.646s
Running aggregation after 61M updates: 0m0.703s
Running aggregation after 62M updates: 0m0.685s

@tommey
Copy link
Author

tommey commented Mar 12, 2024

We have also encountered a memory issue, causing replicas to slowly use up all configured memory amount that wasn't the case before with the regular redis server, without modules and no RediSearch indexing, so now we opted for a custom LUA Redis Function to do the aggregation, which calls KEYS prefix*, then loads the HashMaps with HGETALL, does the aggregation and returns an Array reply with Array items consisting of the tag and 4 counters.

The service performs at a stable 100ms response time, which is 2-3 times worse than it would be with FT.AGGREGATE, if it wouldn't slow down as max_doc_id increases.

I have looked at the BITFIELD type, which would be another way to implement this, but that would raise additional problems to solve around consistency, reading back data in pipelined workflows, in a use-case where everything changes every second.

@liwensen
Copy link

I had the same problem with the latest version(redis/redis-stack:7.2.0-v9):
Some simple JSON data (1K) was created with only 1 record.
Create an index (idx:Test) and then query the data through the index.
FT.SEARCH idx:Test *

(1) Queries are very fast at first.
(2) After trying to update about 1 million times, I started to stop updating the data and then query the data, which takes 200-400ms.
(3) I tried to delete the index and then re-create the index, which was to query the data again very quickly.
FT.INFO idx:Test
FT.DROPINDEX idx:Test

@sofabeat
Copy link

We're using redis-stack server with only redisearch module enabled ver 20813. We observing similar behavior, where we have index with a lot of HSET updates of indexed keys and constantly growing FT.AGGREGATE execution time. We have ~300K keys that updated at average rate of ~800 hset/sec. Standalone Redis, no disk writes, Ubuntu 22.04 LTS server. After rebooting the Redis FT.AGGREGATE execution time is about 400 msec. It continuously growing and reaching 3000 msec after about 2 days of operation.

FT.CREATE metric-idx ON HASH PREFIX 1 metric: 
  SCHEMA pid TAG category1 
  TAG category2 
  TAG metric NUMERIC SORTABLE 
  cnt NUMERIC SORTABLE 
  upd NUMERIC SORTABLE 
  predictedGood NUMERIC SORTABLE 
  predictedBad NUMERIC SORTABLE
metric-idx * WITHCURSOR COUNT 1000 MAXIDLE 30000 GROUPBY 2 @category1 @category2 
        REDUCE MIN 1 @metric AS min_metric 
        REDUCE MAX 1 @metric AS max_metric 
        REDUCE SUM 1 @cnt AS count 
        REDUCE QUANTILE 2 @metric 0.5 AS median 
        REDUCE SUM 1 @predictedGood AS predictedGood 
        REDUCE SUM 1 @predictedBad AS predictedBad

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants