Hard CPU usage on index cache refill #18036

sphinks82 · 2023-02-02T11:54:33Z

My Environment

ArangoDB Version: 3.10.2
Deployment Mode: Single Server
Deployment Strategy: Manual Start in Docker
Configuration: CPU 16 cores, RAM 32GiB
Infrastructure: own
Operating System: Ubuntu 22.04
Total RAM in your machine: 32Gb
Disks in use: HDD
Used Package: Docker - official Docker library

Component, Query & Data

Affected feature:
AQL query using HTTP

AQL query (if applicable):

LET st = FIRST(FOR c IN Company FILTER c.ogrn==@from RETURN c)
LET fin = FIRST(FOR c IN Company FILTER c.ogrn==@to RETURN c)

FOR p IN 1..20 ANY K_PATHS st TO fin
HasNamesake, HasManager, HasFounder, HasFounderRosstat, HasShareholder, HasLocation, HasPhone
LIMIT 10
RETURN p

AQL explain and/or profile (if applicable):
Query String (280 chars, cacheable: false):
LET st = FIRST(FOR c IN Company FILTER c.ogrn==@from RETURN c)
LET fin = FIRST(FOR c IN Company FILTER c.ogrn==@to RETURN c)
FOR p IN 1..20 ANY K_PATHS st TO fin
HasNamesake, HasManager, HasFounder, HasFounderRosstat, HasShareholder, HasLocation, HasPhone
LIMIT 10
RETURN p

Execution plan:
Id NodeType Calls Items Filtered Runtime [s] Comment
1 SingletonNode 1 1 0 0.00000 * ROOT
25 SubqueryStartNode 1 2 0 0.00000 - LET #5 = ( /* subquery begin /
22 IndexNode 1 2 0 0.00014 - FOR c IN Company / persistent index scan, index scan + document lookup /
20 LimitNode 1 2 0 0.00000 - LIMIT 0, 1
26 SubqueryEndNode 1 1 0 0.00001 - RETURN c ) / subquery end /
23 SubqueryStartNode 1 2 0 0.00000 - LET #1 = ( / subquery begin /
21 IndexNode 1 2 0 0.00007 - FOR c IN Company / persistent index scan, index scan + document lookup /
19 LimitNode 1 2 0 0.00000 - LIMIT 0, 1
24 SubqueryEndNode 1 1 0 0.00001 - RETURN c ) / subquery end /
8 CalculationNode 1 1 0 0.00000 - LET st = FIRST(#1) / simple expression /
15 CalculationNode 1 1 0 0.00000 - LET fin = FIRST(#5) / simple expression /
16 EnumeratePathsNode 1 10 0 1.05859 - FOR p / path / IN 1..20 / min..maxPathDepth / ANY K_PATHS st / startnode / TO fin / targetnode */ HasNamesake, HasManager, HasFounder, HasFounderRosstat, HasShareholder, HasLocation, HasPhone
17 LimitNode 1 10 0 0.00001 - LIMIT 0, 10
18 ReturnNode 1 10 0 0.00001 - RETURN p

Indexes used:
By Name Type Collection Unique Sparse Cache Selectivity Fields Stored values Ranges
22 IX_Ogrn persistent Company false false false 95.10 % [ ogrn ] [ ] (c.ogrn == "1024501763483")
21 IX_Ogrn persistent Company false false false 95.10 % [ ogrn ] [ ] (c.ogrn == "1056604407650")
16 edge edge HasFounder false false false 98.71 % [ _to ] [ ] base INBOUND
16 edge edge HasFounder false false false 52.95 % [ _from ] [ ] base OUTBOUND
16 edge edge HasFounderRosstat false false false 96.67 % [ _to ] [ ] base INBOUND
16 edge edge HasFounderRosstat false false false 84.01 % [ _from ] [ ] base OUTBOUND
16 edge edge HasLocation false false false 93.53 % [ _to ] [ ] base INBOUND
16 edge edge HasLocation false false false 82.27 % [ _from ] [ ] base OUTBOUND
16 edge edge HasManager false false false 99.60 % [ _to ] [ ] base INBOUND
16 edge edge HasManager false false false 68.17 % [ _from ] [ ] base OUTBOUND
16 edge edge HasNamesake false false false 93.53 % [ _to ] [ ] base INBOUND
16 edge edge HasNamesake false false false 100.00 % [ _from ] [ ] base OUTBOUND
16 edge edge HasPhone false false false 99.19 % [ _to ] [ ] base INBOUND
16 edge edge HasPhone false false false 76.91 % [ _from ] [ ] base OUTBOUND
16 edge edge HasShareholder false false false 87.55 % [ _to ] [ ] base INBOUND
16 edge edge HasShareholder false false false 28.37 % [ _from ] [ ] base OUTBOUND

k shortest paths on graphs:
Id Vertex collections Edge collections
16 HasNamesake, HasManager, HasFounder, HasFounderRosstat, HasShareholder, HasLocation, HasPhone

Optimization rules applied:
Id RuleName
1 move-calculations-up
2 optimize-subqueries
3 move-calculations-up-2
4 use-indexes
5 remove-filter-covered-by-index
6 remove-unnecessary-calculations-2
7 move-calculations-down
8 splice-subqueries

Query Statistics:
Writes Exec Writes Ign Scan Full Scan Index Cache Hits/Misses Filtered Peak Mem [b] Exec Time [s]
0 0 0 296325 358422 / 6656 0 5963776 1.08050

Query Profile:
Query Stage Duration [s]
initializing 0.00000
parsing 0.00006
optimizing ast 0.00001
loading collections 0.00001
instantiating plan 0.00004
optimizing plan 0.02151
executing 1.05888
finalizing 0.00006

Dataset:
(In the part involved in the query):
Edges collections - 7 (29M + 18M + 24M + 400K + 11K + 16M + 6M = 93.5M total edges)
Vertices collections (linked by this edges) - 4 (12M + 46M + 7M + 5M = 70M total vertices)

Size of your Dataset on disk:
Approx. 70GiB

Problem:
After several minutes of load testing, the CPU is fully loaded. The processor is not released until the end of the load.
Looking at the metrics graphs, we believe that the increase in load occurs when it reaches approximately 50-60% of the memory allocated for the index cache
(rocksdb_cache_allocated - 3.74GiB, rocksdb_cache_limit - 7.32GiB). At the same time, there is a sharp jump in the number of threads (arangodb_process_statistics_number_of_threads) and the number of connections (arangodb_client_connection_statistics_client_connections), although we do not add external connections anymore.

Is it possible to configure the server so that the processes of clearing / refilling the cache do not consume all available resources, but take place in the background?
Or is it a bug in the code, and if so, is the reason known, and the timing of the fix?

The text was updated successfully, but these errors were encountered:

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Hard CPU usage on index cache refill #18036

Hard CPU usage on index cache refill #18036

Hard CPU usage on index cache refill #18036

Hard CPU usage on index cache refill #18036

Comments

My Environment

Component, Query & Data