#openobserve

High Memory Usage Issue in OpenObserve 0.5.1

TLDR Chris reported high memory usage with OpenObserve 0.5.1 when making specific queries, causing out of memory errors. Hengfei suggested attempting without conditions. Chris will raise an official issue regarding the problem.

Powered by Struct AI
Jul 27, 2023 (4 months ago)
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
01:09 PM
just upgraded to 0.5.1 (on-prem) and seeing a big problem.... 2 queriers each with 64GB mem.... restart the queriers.... query the last 1 day of events in a stream... returns 320 M events ok.... memory usage of OO rises to 12.7G in one querier.... now query testing for just 1 field value.... memory usage pretty quickly rises to well over 60 GB in each querier, and the OOM killer steps in on both..... very repeatable.... initially had ZO_MEMORY_CACHE_MAX_SIZE=50000, then tried leaving it out, then tried 20000.... no difference in behaviour.... i haven't set any of the new cache variables that I see have appeared
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
01:14 PM
when the pod start, how many files it loaded?
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
01:14 PM
no pod, just running the binary in a series of VMs
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
01:17 PM
okay, when the OpenObserve start, it should report some logs like this:
[db::file_list::remote] Load file_list [file_list/] begin
[db::file_list::remote] Load file_list [file_list/] gets 670 files
[db::file_list::remote] Load file_list [file_list/] load 670:565100 done
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
01:18 PM
[2023-07-27T13:04:12Z INFO  openobserve::service::db::file_list::remote] Load file_list [file_list/] gets 11410 files
[2023-07-27T13:04:14Z INFO  openobserve::service::db::file_list::remote] Load file_list [file_list/] load 11410:230511 done
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
01:21 PM
thanks, when you fire a query, can you give us the OpenObserve logs. it will print something, like load how many files, and the scan_size.
And what is the memory usage before and after the query.
01:21
Hengfei
01:21 PM
What is your query?
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
01:22 PM
simply: device_name="dev name"
01:29
Chris
01:29 PM
here's the log from one of the queriers.... the query does not finish before OOM kills the process
[2023-07-27T13:02:55Z INFO  openobserve::service::search::sql] sqlparser: stream_name -> "redacted", fields -> [], partition_key -> [("device_name", "redacted", Eq)], full_text -> [], time_range -> Som
e((1690376575921000, 1690462975921000)), order_by -> [], limit -> 0,150
[2023-07-27T13:02:55Z INFO  tracing::span] service:search:grpc:in_wal;
[2023-07-27T13:02:55Z INFO  tracing::span] service:search:grpc:in_storage;
[2023-07-27T13:02:55Z INFO  tracing::span] service:search:grpc:storage:enter;
[2023-07-27T13:02:55Z INFO  openobserve::service::search::grpc::storage] search->storage: org redacted, stream redacted, load files 2143, scan_size 523899602002, compressed_size 21766337881
[2023-07-27T13:02:55Z INFO  tracing::span] service:search:grpc:storage:datafusion;
[2023-07-27T13:02:55Z INFO  openobserve::service::search::datafusion::exec] Query sql: select * FROM tbl   WHERE (_timestamp >= 1690376575921000 AND _timestamp < 1690462975921000) AND device_name='redacted' ORDER BY _timestamp DESC LIMIT 150
[2023-07-27T13:02:55Z INFO  tracing::span] datafusion::storage::nocache::list;
[2023-07-27T13:02:56Z INFO  openobserve::service::search] search->grpc: result node: 2, is_querier: false, total: 0, took: 992, files: 5, scan_size: 101
[2023-07-27T13:02:57Z INFO  openobserve::service::search] search->grpc: result node: 3, is_querier: false, total: 0, took: 1404, files: 5, scan_size: 104
01:36
Chris
01:36 PM
and the other querier had
[2023-07-27T13:02:55Z INFO  openobserve::service::search::grpc::storage] search->storage: org redacted, stream redacted, load files 2142, scan_size 212242226193, compressed_size 9408088229
[2023-07-27T13:02:56Z INFO  openobserve::service::search::grpc::storage] search->storage: org redacted, stream redacted, load files 2142, into memory cache done
01:55
Chris
01:55 PM
just doing the same over a 3 hour period let's me see what happens without it completely running out of memory.... both queriers start using about 9.5G.... during first part of query both rise to about 15G, then drop, then the first querier rises to about 45G beofre completing
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
01:55 PM
select * FROM tbl   WHERE (_timestamp >= 1690376575921000 AND _timestamp < 1690462975921000) AND device_name='redacted' ORDER BY _timestamp DESC LIMIT 150

this is your final query.
01:56
Hengfei
01:56 PM
can you try, without condition, just get the record list for the time range.
01:56
Hengfei
01:56 PM
leave the query editor empty.
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
02:05 PM
for 1-day, no query conditions, the 2 queriers give
[2023-07-27T13:57:08Z INFO  openobserve::service::search::sql] sqlparser: stream_name -> "redacted", fields -> [], partition_key -> [], full_text -> [], time_range -> Some((1690379828171000, 1690466228171000)), order_by -> [], limit -> 0,150
[2023-07-27T13:57:08Z INFO  openobserve::service::search::grpc::storage] search->storage: org redacted, stream redacted, load files 2066, scan_size 504941830625, compressed_size 20971616709

[2023-07-27T13:57:08Z INFO  openobserve::service::search::sql] sqlparser: stream_name -> "redacted", fields -> [], partition_key -> [], full_text -> [], time_range -> Some((1690379828171000, 1690466228171000)), order_by -> [], limit -> 0,150
[2023-07-27T13:57:08Z INFO  openobserve::service::search::grpc::storage] search->storage: org redacted, stream redacted, load files 2065, scan_size 236777136354, compressed_size 10373784759
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
02:05 PM
does it OOM?
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
02:06 PM
no, only when a condition is specified
02:08
Chris
02:08 PM
without the condition, memory usage hardly changes (it's all in cache by this stage)
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
02:34 PM
in the logs we can see it need load 20971616709, 21GB data into memory for search. without where condition, we only run aggregations and fetch first 150 records in the first file.
but with condition, need to load all files to search data, we know the 21GB is after compress, when we search data, we need to uncompress something, the original size is 504941830625, 500GB, even we don't need 500GB, but after uncompress it need more than 21GB memory, so 64GB - 20GB(for cache)-21GB(download files)=20GB, there is only 20GB can use, for uncompress data, maybe it cause OOM.

Can you help create an issue for your case, we will improve it. like do search by partition, every time we only load 10GB data, and search multiple times, in the end, we merge partition search result. it should be work, search large data scale in limit memory usage.
Chris
Photo of md5-7d2796ababc14477f4c09abc2e8edb05
Chris
03:27 PM
as discussed will raise an issue...

Thinking more though.... i would guess that most searches are ordered by time.... and i have often noticed that most of the search time is spent determining the number of events in the time period for the histogram and total.... often we don't need either of those, and if the need to get those could be switched off (merely turning off the histogram doesn't stop it counting), then just locating the first n events could be hugely faster? (possibly cache the first few hundred so you have several screens) .... which might affect the scale/operation of what you describe above?
Jul 28, 2023 (4 months ago)
Hengfei
Photo of md5-c30bb074b7d997d2cd6e689678b65dc1
Hengfei
01:46 AM
Image 1 for
01:46
Hengfei
01:46 AM
First you can switch off Histogram at here.
01:47
Hengfei
01:47 AM
Yes, without Histogram will reduce some costs. but with conditions, it still needs more memory.

OpenObserve

OpenObserve is an open-source, petabyte-scale observability platform for the cloud native realm, offering a 10x cost reduction and 140x less storage use compared to competitors like Elasticsearch or Splunk. Built in Rust for exceptional performance, it offers comprehensive features like logs, metrics, traces, dashboards, and more | Knowledge Base powered by Struct.AI

Indexed 404 threads (74% resolved)

Join Our Community

Similar Threads

Query and Issue with Disparity in Stream Stats and Disk Usage

Karan shared a query and noted a disparity in stream stats and disk usage. After troubleshooting, Hengfei identified a bug and advised on stats refresh. Ashish confirmed that the disk size was the accurate measure and they would investigate the stats calculation.

10

52
1mo
Solved

Erroneous Triggering of Alarm in 0.5.1

Chris expressed experiencing occasional erroneous alerts trigger on a specific stream query. Ashish suggested the issue might be linked to a known duplicates bug. Uncertain, Chris decided to monitor the issue further and report if it persists.

1

30
3mo

Troubleshooting High CPU and Memory Usage in Zinc Service

Zygimantas experienced high CPU and memory usage in zinc service while querying large datasets. Hengfei offered suggestions to optimize and test for local disk and S3 usage. Gaby and Prabhat discussed SIMD tag performance.

5

68
6mo

ZO Kubernetes Issues: Query Log Error and Adding Users

Sa had issues with querying logs in ZO on Kubernetes and creating users. Hengfei provided solutions for both problems, including updating with a dev version and setting memory cache values.

4

100
6mo
Solved

OpenObserve issues with FluentBit and Dashboard

Alejandro experienced issues with FluentBit losing connection with OpenObserve and discarding logs, and an error when saving a chart on the OpenObserve dashboard. Prabhat could not identify the cause of record loss. However, potential solutions were suggested to save the dashboard with a string-type filter instead of integer one.

3

11
2mo