influxdata / influxdata/influxdb
Multiple sub-queries performance issue
- Dominant language
- Rust
- Stars
- 31.7k
- Forks
- 3.7k
- Avg merge
- 13h 37m
- Merged PRs (30d)
- 8
Description
__Steps to reproduce:__
List the minimal actions needed to reproduce the behavior.
1. I have data stored in database in the following format:
```
> SELECT * FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z'
name: jti.firewall_stats
time bytes component_id device filter_counter_name filter_name filter_timestamp packets
---- ----- ------------ ------ ------------------- ----------- ---------------- -------
2020-03-15T08:00:09Z 229274168676 7 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1569390826 2729454389
2020-03-15T08:00:46Z 229274319876 7 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1569390826 2729456189
2020-03-15T08:01:24Z 229274483676 7 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1569390826 2729458139
2020-03-15T08:01:31Z 1468330080 3 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1584015614 17480120
2020-03-15T08:02:00Z 229274645796 7 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1569390826 2729460069
2020-03-15T08:02:38Z 229274811276 7 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1569390826 2729462039
2020-03-15T08:03:18Z 1468977888 3 RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 1584015614 17487832
...
```
2. Now I want to summarize counters traffic on 15 min time interval (group by device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m) )and I use this "composite" query:
```
SELECT SUM("nnd_bytes") AS "sum_bytes", SUM("nnd_packets") AS "sum_packets", COUNT("nnd_bytes") AS "samples" FROM (
SELECT NON_NEGATIVE_DIFFERENCE("bytes") AS "nnd_bytes", NON_NEGATIVE_DIFFERENCE("packets") AS "nnd_packets" FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp)
WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m)
> SELECT SUM("nnd_bytes") AS "sum_bytes", SUM("nnd_packets") AS "sum_packets", COUNT("nnd_bytes") AS "samples" FROM ( SELECT NON_NEGATIVE_DIFFERENCE("bytes") AS "nnd_bytes", NON_NEGATIVE_DIFFERENCE("packets") AS "nnd_packets" FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp) WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m)
name: jti.firewall_stats
tags: component_id=3, device=RMTB-B21-re1:10.255.254.100, filter_counter_name=1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666, filter_name=20190605-150-U-999, filter_timestamp=1584015614
time sum_bytes sum_packets samples
---- --------- ----------- -------
2020-03-15T08:00:00Z 4862004 57881 8
2020-03-15T08:15:00Z 5106024 60786 8
name: jti.firewall_stats
tags: component_id=7, device=RMTB-B21-re1:10.255.254.100, filter_counter_name=1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666, filter_name=20190605-150-U-999, filter_timestamp=1569390826
time sum_bytes sum_packets samples
---- --------- ----------- -------
2020-03-15T08:00:00Z 3738840 44510 23
2020-03-15T08:15:00Z 3833760 45640 24
```
This works fine for 6000 counters which have ~112K samples, it needs ~30 sec
3. Now I want to summarize this result for all counters with the same `filter_counter_name`, but different `component_id` and `filter_timestamp`, so I use another level of query with corresponding grouping:
```
SELECT SUM("sum_bytes") AS "total_bytes", SUM("sum_packets") AS "total_packets", SUM("samples") AS "total_samples", COUNT(DISTINCT("component_id")) AS "mpcs", COUNT(DISTINCT("filter_timestamp")) AS "timestamps" FROM (
SELECT SUM("nnd_bytes") AS "sum_bytes", SUM("nnd_packets") AS "sum_packets", COUNT("nnd_bytes") AS "samples" FROM (
SELECT NON_NEGATIVE_DIFFERENCE("bytes") AS "nnd_bytes", NON_NEGATIVE_DIFFERENCE("packets") AS "nnd_packets" FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp)
WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m) )
WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,filter_name,filter_counter_name,time(15m)
> SELECT SUM("sum_bytes") AS "total_bytes", SUM("sum_packets") AS "total_packets", SUM("samples") AS "total_samples", COUNT(DISTINCT("component_id")) AS "mpcs", COUNT(DISTINCT("filter_timestamp")) AS "timestamps" FROM ( SELECT SUM("nnd_bytes") AS "sum_bytes", SUM("nnd_packets") AS "sum_packets", COUNT("nnd_bytes") AS "samples" FROM ( SELECT NON_NEGATIVE_DIFFERENCE("bytes") AS "nnd_bytes", NON_NEGATIVE_DIFFERENCE("packets") AS "nnd_packets" FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp) WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m) ) WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,filter_name,filter_counter_name,time(15m)
name: jti.firewall_stats
tags: device=RMTB-B21-re1:10.255.254.100, filter_counter_name=1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666, filter_name=20190605-150-U-999
time total_bytes total_packets total_samples mpcs timestamps
---- ----------- ------------- ------------- ---- ----------
2020-03-15T08:00:00Z 8600844 102391 31 2 2
2020-03-15T08:15:00Z 8939784 106426 32 2 2
```
This will effectively summarize 2 counter which have different `component_id` (values 3 ad 7) from step 2, into 1 result - so summarizing 6000 results to 3000 results.
However, for 6000 result this takes around ~6 min, instead of ~30 sec which I would expect.
4. By coincidence, I found that if I add another layer of query on top of this, using just `SELECT *`, this will decrease the results time to expected ~30 sec. Additionally, the result will return the results from 2020-03-15T07:45:00Z, which in fact returns different but correct result for period 2020-03-15T08:00:00Z, because NON_NEGATIVE_DIFFERENCE function needs the sample from the previous interval to have correct calculation.
```
SELECT * FROM (
SELECT SUM("sum_bytes") AS "total_bytes", SUM("sum_packets") AS "total_packets", SUM("samples") AS "total_samples", COUNT(DISTINCT("component_id")) AS "mpcs", COUNT(DISTINCT("filter_timestamp")) AS "timestamps" FROM (
SELECT SUM("nnd_bytes") AS "sum_bytes", SUM("nnd_packets") AS "sum_packets", COUNT("nnd_bytes") AS "samples" FROM (
SELECT NON_NEGATIVE_DIFFERENCE("bytes") AS "nnd_bytes", NON_NEGATIVE_DIFFERENCE("packets") AS "nnd_packets" FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp)
WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m) )
WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,filter_name,filter_counter_name,time(15m)
)
> SELECT * FROM (SELECT SUM("sum_bytes") AS "total_bytes", SUM("sum_packets") AS "total_packets", SUM("samples") AS "total_samples", COUNT(DISTINCT("component_id")) AS "mpcs", COUNT(DISTINCT("filter_timestamp")) AS "timestamps" FROM ( SELECT SUM("nnd_bytes") AS "sum_bytes", SUM("nnd_packets") AS "sum_packets", COUNT("nnd_bytes") AS "samples" FROM ( SELECT NON_NEGATIVE_DIFFERENCE("bytes") AS "nnd_bytes", NON_NEGATIVE_DIFFERENCE("packets") AS "nnd_packets" FROM "juniper".."jti.firewall_stats" WHERE filter_counter_name =~ /1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666/ AND time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp) WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,component_id,filter_name,filter_counter_name,filter_timestamp,time(15m) ) WHERE time >= '2020-03-15T08:00:00Z' AND time < '2020-03-15T08:30:00Z' GROUP BY device,filter_name,filter_counter_name,time(15m) )
name: jti.firewall_stats
time device filter_counter_name filter_name mpcs timestamps total_bytes total_packets total_samples
---- ------ ------------------- ----------- ---- ---------- ----------- ------------- -------------
2020-03-15T07:45:00Z RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 2 2 8813952 104928 31
2020-03-15T08:00:00Z RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 2 2 9357852 111403 33
2020-03-15T08:15:00Z RMTB-B21-re1:10.255.254.100 1-0_0_0_0-0-0_0_0_0-0-U-et-0_3_0_150-666 20190605-150-U-999 2 2 8939784 106426 32
```
This leads me to think that something is messed in some query optimizations in step 3, which are not processed as it should be. This results in the very high processing time.
I guess this is deliberately changed, since I also notice difference behavior in InfluxDB 1.7.9 which is used here and InfluxDB 1.3.6 where:
- v 1.7.9 time grouping with NON_NEGATIVE_DIFFERENCE do NOT take into account the last sample from the previous time interval, so the actual calculation "misses" one sample
- v 1.3.6 time grouping with NON_NEGATIVE_DIFFERENCE take into account the sample from the previous interval and provides the previous interval in the results, so it does not miss one sample per grouping.
From my p
__Expected behavior:__
Describe what you expected to happen.
Explained above
__Actual behavior:__
Describe What actually happened.
Explained above
__Environment info:__
* System info: Run `uname -srm` and copy the output here
Running InfluxDB in Docker container
```
root@db_1:/# uname -srm
Linux 5.3.0-40-generic x86_64
```
* InfluxDB version: Run `influxd version` and copy the output here
```
root@db_1:/# influxd version
InfluxDB v1.7.9 (git: 1.7 23bc63d43a8dc05f53afa46e3526ebb5578f3d88)
```
* Other relevant environment details: Container runtime, disk info, etc
```
$ docker --version
Docker version 19.03.7, build 7141c199a2
```
__Config:__
Copy any non-default config values here or attach the full config as a gist or file.
__Logs:__
Include snippet of errors in log.
__Performance:__
Generate profiles with the following commands for bugs related to performance, locking, out of memory (OOM), etc.
```sh
# Commands should be run when the bug is actively happening.
# Note: This command will run for at least 30 seconds.
curl -o profiles.tar.gz "http://localhost:8086/debug/pprof/all?cpu=true"
curl -o vars.txt "http://localhost:8086/debug/vars"
iostat -xd 1 30 > iostat.txt
# Attach the `profiles.tar.gz`, `vars.txt`, and `iostat.txt` output files.
```
Contributor guide
Research direction
The report does not name any repository files, tests, or entry points. Start by reproducing the nested queries from steps 3 and 4 with the supplied dataset, then compare their execution time and returned time buckets; done means identifying and correcting the suspected optimization behavior without regressing NON_NEGATIVE_DIFFERENCE results.
Written by the indexing model from the issue text.
Assessment
- Domain
- databases, performance
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 20/100