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
23
4mo
Jul 27, 2023 (4 months ago)
Chris
Chris
01:09 PMjust 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
Hengfei
01:14 PMwhen the pod start, how many files it loaded?
Chris
Chris
01:14 PMno pod, just running the binary in a series of VMs
Hengfei
Hengfei
01:17 PMokay, 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 doneChris
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 doneHengfei
Hengfei
01:21 PMthanks, 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.
And what is the memory usage before and after the query.
01:21
Hengfei
01:21 PMWhat is your query?
Chris
Chris
01:22 PMsimply: device_name="dev name"
01:29
Chris
01:29 PMhere'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: 10401:36
Chris
01:36 PMand 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 done01:55
Chris
01:55 PMjust 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
Hengfei
01:55 PMselect * FROM tbl WHERE (_timestamp >= 1690376575921000 AND _timestamp < 1690462975921000) AND device_name='redacted' ORDER BY _timestamp DESC LIMIT 150this is your final query.
01:56
Hengfei
01:56 PMcan you try, without condition, just get the record list for the time range.
01:56
Hengfei
01:56 PMleave the query editor empty.
Chris
Chris
02:05 PMfor 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 10373784759Hengfei
Hengfei
02:05 PMdoes it OOM?
Chris
Chris
02:06 PMno, only when a condition is specified
02:08
Chris
02:08 PMwithout the condition, memory usage hardly changes (it's all in cache by this stage)
Hengfei
Hengfei
02:34 PMin 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.
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
Chris
03:27 PMas 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?
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
Hengfei
01:46 AM
01:46
Hengfei
01:46 AMFirst you can switch off Histogram at here.
01:47
Hengfei
01:47 AMYes, 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)
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.
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.
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.
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.
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.
11
2mo