TT returns inconsistent data on query

jens-ylja commented 1 year ago

Hallo,

I experimented a lot with the line format (OpenTSDB vs. Influx) and general layout of my time series. With this the data stored in TT became some kind of a huddle. So I decided to clean up. But don't want to loose my data and decided too, to fetch them all from TT, reorganize, cleanup, etc. and finally re-insert to a new clean TT instance.

Unfortunately I failed with the first task - fetch them all. I tried the following (as bash script):

metric=some.metric
for month in 3 4
do
   for range in `ls -1rt /ticktock/ticktock/data/2023/${month} | grep -v '.back'`
   do
       wget -O - 'http://localhost:6182/api/query?start='`echo $range | sed -e 's/[.]/\&end=/'`'&m=none:'${metric} >  {range}.${metric}.json
       sleep 1
   done
done

This wrote me some files with data and some with only []. Running it a second time maybe returned different results.

To verify if all the data is gone, I checked with Grafana and sometimes got data, some other times not. After waiting a couple of minutes and just running the Grafana query again, all is fine.

Finally I checked the logs and found a lot of error messages like:

2023-04-22 14:09:48.658 [ERROR] [qexe_task_0] Failed to mmap file /ticktock/ticktock/data/2023/4/1681084800.1681171200/data.0, errno = 12 2023-04-22 14:09:48.659 [ERROR] [qexe_task_0] Caught exception while performing query.

Maybe these are the reasons for the [] answers.

I'm running TT (still version 0.11.4) on a ODROID HC1 which has a total of 2 GB RAM only. Is it a valid assumption this low memory availability causes the misbehaviour?

The effect seems to self-heal after a while. If the low memory pressure is the reason I would propose to answer with HTTP 503 (temporary unavailable) instead of 200 and []. The 503 status code - in my opinion - would transport quite the correct information: "For now I cannot answer, please try later."

A a workaround, I will slow down my queries for data export or even move all (temporarily) to a larger scale machine. But I assume, the same effect will happen if I run a query over the full time range (start == begin of March, end == now).

Thanks Jens

ylin30 commented 1 year ago

hi Jen，I haven’t looked at your case closely yet but in general errno 12 indicates out of memory. Very possible that TT can’t fetch data with mmap due to OOM. Sometimes in 32bits OS TT may run out of virtual memory but seem unlikely in your case.

Btw, Please use latest version 0.11.7 if possible.

Sent from my iPhoneOn Apr 22, 2023, at 5:49 AM,

ylin30 commented 1 year ago

Jens, how big is your data? Would you mind to share your data with us for a repro?

I experimented a lot with the line format (OpenTSDB vs. Influx) and general layout of my time series.

OpenTSDB does not support influx line protocol, doesn’t it? For writes It only supports http json and tcp plain put, ASFAIK. Maybe I missed something?

Regards Yi

ytyou commented 1 year ago

Hi Jens,

You are correct on the 503 response. We will make the change in the next release. Thanks.

As for using wget to retrieve large amount of data in one shot, it's not going to work, unfortunately. Our HTTP server does not support chunked encoding, so that means we will try to return all the data in one response, and it will result in OOM.

To dump all data out, your best bet is the 'inspect' tool. For example,

bin/inspect -v -d /ticktock/ticktock/data

It will spit out all your data on stdout, although the format is not ideal. We can introduce a new output format that can be used to inject them back into TT, if that helps.

Thanks Yongtao

jens-ylja commented 1 year ago

hi Jen，I haven’t looked at your case closely yet but in general errno 12 indicates out of memory. Very possible that TT can’t fetch data with mmap due to OOM. Sometimes in 32bits OS TT may run out of virtual memory but seem unlikely in your case.

I transferred all data to my laptop (i7-6600U CPU, 16G Memory, running TT 0.11.7) and re-executed just the same queries -> all worked fine.

Btw, Please use latest version 0.11.7 if possible. Sent from my iPhoneOn Apr 22, 2023, at 5:49 AM,

I'll switch soon :)

jens-ylja commented 1 year ago

Jens, how big is your data? Would you mind to share your data with us for a repro?

It's about 50 megabytes as gzip compressed tar. I think about sharing but believe you won't be able to reproduce on a larger scale machine. As I wrote above all worked fine for me when running TT on my laptop.

Maybe repro would be possible on a Raspberry Pi Model 2B - but this is significantly smaller than my Odroid HC1: HC1: ARM Cortex-A15 & Cortex-A7 big.LITTLE, Octa-Core, 2GB LPDDR3 RAM Pi 2B: ARM Cortex-A7 Dual-Core, 1 GB LPDDR2 RAM

A repro should be possible when using an Odroid XU4 which was the base platform for the HC1.

I experimented a lot with the line format (OpenTSDB vs. Influx) and general layout of my time series.

OpenTSDB does not support influx line protocol, doesn’t it? For writes It only supports http json and tcp plain put, ASFAIK. Maybe I missed something?

Yes, sure. But TT supports both the line protocols of OpenTSDB and Influx. I tested in mix with both of them when writing data to TT to find out which one fits better for me. Finally I decided to use the Influx line protocol.

Regards Yi

jens-ylja commented 1 year ago

Hi Jens,

You are correct on the 503 response. We will make the change in the next release. Thanks.

As for using wget to retrieve large amount of data in one shot, it's not going to work, unfortunately. Our HTTP server does not support chunked encoding, so that means we will try to return all the data in one response, and it will result in OOM.

The largest response I got was smaller than half a megabyte. This, I believe, shouldn't be a reason for OOM. I believe the way I queried the data is more likely a problem because it caused TT to load all data files in a very short period of time.

To dump all data out, your best bet is the 'inspect' tool. For example,

bin/inspect -v -d /ticktock/ticktock/data

It will spit out all your data on stdout, although the format is not ideal. We can introduce a new output format that can be used to inject them back into TT, if that helps.

I tried inspect this morning, but am not really able to interpret the data dumped there. Most of the lines I can understand in some way, e.g. ts = 1679253030, value = 91.000. But a lot of lines feel curious, e.g. ts = 27530, value = 2620.000 - quite the same format as above, but whereas 1679253030 is a time stamp, 27530 isn't really. Finally there are lines like ts-id = 3 - I interpret them as a marker for the time series which is dumped. But where are the metadata telling me what series 3 really is?

Thanks Yongtao

Thanks Jens

jens-ylja commented 1 year ago

Hi,

I just updated to 0.11.7 and executed just another experiment (running on the ARMv7 machine again):

stop TT instance
start TT instance

execute a single query with Grafana (query for 30 days):

POST /api/query HTTP/1.1
X-Grafana-Referer: http://localhost:3000/dashboard/new?orgId=1&from=1678921200000&to=now

{"start":1678921200000,"queries":[{"metric":"some.series","aggregator":"first","downsample":"30m-avg","tags":{"_field":"*"}}],"msResolution":false,"globalAnnotations":true}

this gave me data for about 16 days only and some Failed to mmap file ..., errno = 12

When executing quite the same with exactly the same database and TT running on my i7-6600U CPU, 16G Memory, all works fine. Seems really to be a problem related to either the 32 bit architecture or the small amount of total system memory.

Some infos regarding my database:

number of series 49 (from bin/inspect)
total dps = 6508557 (from bin/inspect)
time range of data within the database 2023-03-19 to 2023-04-16
data granularity at 10s for most of the contained series, 1m for the remainder

jens-ylja commented 1 year ago

Hello Yongtao,

As for using wget to retrieve large amount of data in one shot, it's not going to work, unfortunately. Our HTTP server does not support chunked encoding, so that means we will try to return all the data in one response, and it will result in OOM.

I just checked about this. When querying some of my metrics for a whole day, I receive a HTTP 413 Request Entity Too Large response and can find a log entry stating [http_40_task_0] response too large, 524090 >= 524090.

So this is handled correctly without an OOM happening.

I ran this a second time with the config property tcp.buffer.size set to 1024kb (default is 512kb). Than the HTTP 413 was gone and TT gave me a response with about 650kB.

Thanks Jens

ylin30 commented 1 year ago

Yes, sure. But TT supports both the line protocols of OpenTSDB and Influx.

I see you refer OpenTSDB plain put (e.g., put testM1 1633412175 123 host=foo) as OpenTSDB line protocol.

I tested in mix with both of them when writing data to TT to find out which one fits better for me. Finally I decided to use the Influx line protocol.

Yes, Influx line protocol is the best. We are stress-testing Json, opentsdb plain put, and influx-line right now. Will publish results in wiki.

I tried inspect this morning, but am not really able to interpret the data dumped there. Most of the lines I can understand in some way, e.g. ts = 1679253030, value = 91.000. But a lot of lines feel curious, e.g. ts = 27530, value = 2620.000 - quite the same format as above, but whereas 1679253030 is a time stamp, 27530 isn't really.

27530 is delta of timestamp if I remember correctly. @ytyou can confirm.

Finally there are lines like ts-id = 3 - I interpret them as a marker for the time series which is dumped. But where are the metadata telling me what series 3 really is?

You can find ts-id to ts<metric, tags> in data/ticktock.meta which is a text file. Inspect is an internal tool. We use it to verify data integrity and missing points etc. Not very friendly to end users.

ylin30 commented 1 year ago

this gave me data for about 16 days only and some Failed to mmap file ..., errno = 12

We use mmap in loading data files for queries. This indicates OOM.

When executing quite the same with exactly the same database and TT running on my i7-6600U CPU, 16G Memory, all works fine. Seems really to be a problem related to either the 32 bit architecture or the small amount of total system memory.

Some infos regarding my database:

number of series 49 (from bin/inspect)

total dps = 6508557 (from bin/inspect)

time range of data within the database 2023-03-19 to 2023-04-16

data granularity at 10s for most of the contained series, 1m for the remainder

The canonical data size of 6.5M data points is only 12MB (1-2B/DataPoint in avg). It seems that the OOM above is more likely due to virtual memory than due to physical memory, especially since it is on a 32-bit Arm OS. Did you happen to observe the size of RSS and VM during the query? TOP may be enough. We will try if we can repro with the similar data size.

If it is indeed OOM (very likely), any suggestions to response code and status?

I ran this a second time with the config property tcp.buffer.size set to 1024kb (default is 512kb). Than the HTTP 413 was gone and TT gave me a response with about 650kB.

Yes, if query result size is larger than tcp.buffer.size, the query will fail. You have to reduce result size, either by increasing downsample interval or reducing query range etc.

ylin30 commented 1 year ago

Some infos regarding my database:

number of series 49 (from bin/inspect)

total dps = 6508557 (from bin/inspect)

time range of data within the database 2023-03-19 to 2023-04-16

data granularity at 10s for most of the contained series, 1m for the remainder

@jens-ylja Are these numbers for the whole DB, or just specific to your query results? Can you pls share the TicktockDB config with us? How many files in each TSDB and what is the file size?

jens-ylja commented 1 year ago

Hello @ylin30, please find some answers inline.

Did you happen to observe the size of RSS and VM during the query? TOP may be enough.

Not yet, I'll try to capture it today.

If it is indeed OOM (very likely), any suggestions to response code and status?

I would propose a HTTP 503 Service Unavailable.

jens-ylja commented 1 year ago

Some infos regarding my database:

number of series 49 (from bin/inspect)

total dps = 6508557 (from bin/inspect)

time range of data within the database 2023-03-19 to 2023-04-16

data granularity at 10s for most of the contained series, 1m for the remainder

@jens-ylja Are these numbers for the whole DB, or just specific to your query results? Can you pls share the TicktockDB config with us? How many files in each TSDB and what is the file size?

These are the counters of the whole DB. My TicktockDB config is almost the default. I'm running with -c and the config file is:

ticktock.home = /home/ylja/ticktock/ticktock-origin

http.server.port = 5000
# OpenTSDB,InfluxDB
tcp.server.port = 5001,5002

Attached please find a listing of all data files (*.back directories left out) of the complete DB. ticktock-origin.listing.txt

jens-ylja commented 1 year ago

Did you happen to observe the size of RSS and VM during the query? TOP may be enough.

I just executed a query accessing data from a test instance (clone from origin) for the last 15 days - which was working. Before query execution state:

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
26865     1 662148  5248  0.2  0.7 ./tt -d -r -c ticktock-poc/tt.conf

After query execution state:

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
26865     1 1743876 7652  0.3  0.7 ./tt -d -r -c ticktock-poc/tt.conf

Next try with a larger clone. Before query execution (instance started some seconds ago):

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
27317     1 658568  3740  0.1  6.6 ./tt -d -r -c ticktock-1/tt.conf

After query execution - producing four errno = 12 log statements:

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
27317     1 2907520 5108  0.2  1.8 ./tt -d -r -c ticktock-1/tt.conf

Indeed these errors seem to be related to the limit for the virtual memory size. The overall address range limit for the 32 bit ARMs is 4GB. Depending on the OS the max virtual memory for user processes is - according to some quick Google searches - between 3,4GB and little more then 2GB (2907520 is about 2.8GB).

Do I have any chance to influence the vmem usage of TT? 2.8GB of virtual memory for a database of less than 100MB should be large enough. Seems there are some huge gaps in vmem space usage.

ylin30 commented 1 year ago

Indeed these errors seem to be related to the limit for the virtual memory size. The overall address range limit for the 32 bit ARMs is 4GB. Depending on the OS the max virtual memory for user processes is - according to some quick Google searches - between 3,4GB and little more then 2GB (2907520 is about 2.8GB).

It is consistent with our observation. TT will go OOM if virtual mem is 2.5-3GB.

Do I have any chance to influence the vmem usage of TT? 2.8GB of virtual memory for a database of less than 100MB should be large enough. Seems there are some huge gaps in vmem space usage.

2.8GB vsz doesn't make sense since your DB is around 100MB. BTW, each data file is configured to keep 2**15=32768 pages which corresponds to 4MB by default. Unless you have 600 data files opened, your vsz mem should not be that large. I don't know if I can repro it but we will try in RPI env.

If it is indeed OOM (very likely), any suggestions to response code and status?

I would propose a HTTP 503 Service Unavailable.

Fix is ready in dev by @ytyou. No partial results is returned. And resp code = 503. Will be released in 0.11.8.

I tried inspect this morning, but am not really able to interpret the data dumped there. Most of the lines I can understand in some way, e.g. ts = 1679253030, value = 91.000. But a lot of lines feel curious, e.g. ts = 27530, value = 2620.000 - quite the same format as above, but whereas 1679253030 is a time stamp, 27530 isn't really.

27530 is delta of timestamp if I remember correctly. @ytyou can confirm.

It is indeed a bug in inspect. Fix is ready in dev by @ytyou . Will be released in 0.11.8.

jens-ylja commented 1 year ago

I cross checked the memory behaviour with almost the same DB on my Laptop (i7-6600U CPU, 16G Memory, Ubuntu 20.04 LTS) I see the following:

TT instance is new-born:

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
 164423    2429 2374140 4060  0.0  2.2 ./tt -d -r -c ticktock-1/tt.conf

After query execution (which worked without an error):

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
 164423    2429 6203860 6772  0.0  0.9 ./tt -d -r -c ticktock-1/tt.conf

This is a diff in vmem of almost 4GB - very large too in my opinion.

BTW - the complete database I used for this test is:

$ ls -hgn `find . -name 'data.*' | grep -v '.back'`
-rw-rw-r-- 1 1001  57K Mär 27 03:41 ./2023/3/1679184000.1679270400/data.0
-rw-rw-r-- 1 1001 160K Mär 28 03:41 ./2023/3/1679270400.1679356800/data.0
-rw-rw-r-- 1 1001 170K Mär 29 03:41 ./2023/3/1679356800.1679443200/data.0
-rw-rw-r-- 1 1001 167K Mär 30 03:41 ./2023/3/1679443200.1679529600/data.0
-rw-rw-r-- 1 1001 165K Mär 31 03:41 ./2023/3/1679529600.1679616000/data.0
-rw-rw-r-- 1 1001 163K Apr  1 03:41 ./2023/3/1679616000.1679702400/data.0
-rw-rw-r-- 1 1001 208K Apr  2 02:45 ./2023/3/1679702400.1679788800/data.0
-rw-rw-r-- 1 1001 145K Apr  3 02:48 ./2023/3/1679788800.1679875200/data.0
-rw-rw-r-- 1 1001 145K Apr  4 02:48 ./2023/3/1679875200.1679961600/data.0
-rw-rw-r-- 1 1001 151K Apr  5 02:48 ./2023/3/1679961600.1680048000/data.0
-rw-rw-r-- 1 1001 143K Apr  6 02:48 ./2023/3/1680048000.1680134400/data.0
-rw-rw-r-- 1 1001 146K Apr  7 02:48 ./2023/3/1680134400.1680220800/data.0
-rw-rw-r-- 1 1001 146K Apr  9 00:28 ./2023/3/1680220800.1680307200/data.0
-rw-rw-r-- 1 1001 175K Apr  9 02:28 ./2023/4/1680307200.1680393600/data.0
-rw-rw-r-- 1 1001 217K Apr 10 02:35 ./2023/4/1680393600.1680480000/data.0
-rw-rw-r-- 1 1001 310K Apr 11 02:35 ./2023/4/1680480000.1680566400/data.0
-rw-rw-r-- 1 1001 521K Apr 12 02:35 ./2023/4/1680566400.1680652800/data.0
-rw-rw-r-- 1 1001 513K Apr 13 02:35 ./2023/4/1680652800.1680739200/data.0
-rw-rw-r-- 1 1001 516K Apr 14 02:35 ./2023/4/1680739200.1680825600/data.0
-rw-rw-r-- 1 1001 508K Apr 15 02:35 ./2023/4/1680825600.1680912000/data.0
-rw-rw-r-- 1 1001 222K Apr 16 03:57 ./2023/4/1680912000.1680998400/data.0
-rw-rw-r-- 1 1001 470K Apr 17 03:57 ./2023/4/1680998400.1681084800/data.0
-rw-rw-r-- 1 1001 241K Apr 18 03:57 ./2023/4/1681084800.1681171200/data.0
-rw-rw-r-- 1 1001 147K Apr 19 03:57 ./2023/4/1681171200.1681257600/data.0
-rw-rw-r-- 1 1001 142K Apr 20 03:57 ./2023/4/1681257600.1681344000/data.0
-rw-rw-r-- 1 1001 143K Apr 21 03:57 ./2023/4/1681344000.1681430400/data.0
-rw-rw-r-- 1 1001 141K Apr 22 03:57 ./2023/4/1681430400.1681516800/data.0
-rw-rw-r-- 1 1001 145K Apr 24 00:11 ./2023/4/1681516800.1681603200/data.0
-rw-rw-r-- 1 1001 124K Apr 24 02:11 ./2023/4/1681603200.1681689600/data.0

ytyou commented 1 year ago

"This is a diff in vmem of almost 4GB - very large too in my opinion."

I agree. We will look into this...

ylin30 commented 1 year ago

TT instance is new-born:

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
 164423    2429 2374140 4060  0.0  2.2 ./tt -d -r -c ticktock-1/tt.conf

I verified that vsize was already 2GB (VmSize: 1917492 kB) once I started TT from scratch. It was on a X86 ubuntu 22.04 64bit.

Updated: vsize of TT on fresh start (x86, 64bit Ubuntu 22.04):

0.11.7 - 1.9GB
0.11.0 - 1.5
0.10.0 - 1.2
0.5.0 - 1.2
0.4.0 - 1.2
0.3.1 - 1.2

ylin30 commented 1 year ago

Did you happen to observe the size of RSS and VM during the query? TOP may be enough.

I just executed a query accessing data from a test instance (clone from origin) for the last 15 days - which was working. Before query execution state:
$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
26865     1 662148  5248  0.2  0.7 ./tt -d -r -c ticktock-poc/tt.conf

@jens-ylja I assume you ran the test in a 8core cpu, 32bit OS. I simulate your scenario by setting http.listener.count and tcp.listener.count to 8 (basically 1 core 1 listener count) in RPI-0-w. You can verify that TT should have 71 threads (ps -eLf, search for NLWP(Number Light Weight Process) col.

I checked TT's mem usage with pmap -x <id>.

ylin30@raspberrypi:~/ticktock $ pmap -x 3681 > /tmp/tt.pmap.fresh
ylin30@raspberrypi:~/ticktock $ grep "total kB" /tmp/tt.pmap.fresh
total kB  580980    4284    1160

The vsize is 580980kB, RSS 4284kB. So this is consistent with your case.

After query execution state:

$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
26865     1 1743876 7652  0.3  0.7 ./tt -d -r -c ticktock-poc/tt.conf

I backfilled 30 days data (at 10 sec interval) of 50 time series. After backfill, TT's vsize and rss remained almost the same. I then issued 13 days query on 50 time series. Query succeeded.

ylin30@raspberrypi:~/ticktock $ curl -v 'http://localhost:6182/api/query?start=1530576000000&end=1531785600000&m=avg:30m-avg:g_0'

I checked TT's vsize and rss grew to 654MB and 11MB. They are significantly smaller than yours (from 662MB to 1.7GB).

ylin30@raspberrypi:~/ticktock $ pmap -x 3681 > /tmp/tt.pmap.after.query13d
ylin30@raspberrypi:~/ticktock $ grep "total kB" /tmp/tt.pmap.after.query13d
total kB  653836   11376    1912

Next try with a larger clone. Before query execution (instance started some seconds ago):
$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
27317     1 658568  3740  0.1  6.6 ./tt -d -r -c ticktock-1/tt.conf
After query execution - producing four errno = 12 log statements:
$ ps -o pid,ppid,vsize,rss,%mem,%cpu,command ax | grep ./tt
27317     1 2907520 5108  0.2  1.8 ./tt -d -r -c ticktock-1/tt.conf

I continued with 30 days query and it succeeded. And the final vsize of TT was 738MB, significantly smaller than yours (2.9GB).

ylin30@raspberrypi:~/ticktock $ curl -v 'http://localhost:6182/api/query?start=1530576000000&m=avg:30m-avg:g_0'
...
ylin30@raspberrypi:~/ticktock $ pmap -x 3681 > /tmp/tt.pmap.after.query30d
ylin30@raspberrypi:~/ticktock $ grep "total kB" /tmp/tt.pmap.after.query30d
total kB  738088   19376    2108

So we can repro the vsize value is expected at fresh start. However, vsize after query can't be reproed.

Do I have any chance to influence the vmem usage of TT? 2.8GB of virtual memory for a database of less than 100MB should be large enough. Seems there are some huge gaps in vmem space usage.

In general, TT vsize is affected by a). number of threads , b). and number of files (data and headers) opened.

For a), you can limit number of listeners to number of cpu cores (as default). It is hard to estimate and control exactly how much vsize they cost. But In 32bit, each thread will reserve 8MB vsize for its stack. In 64bit, there will be 64MB more reserved for heap (shared by other threads too, I think). There is a glibc flag to control but we don't want to change it. That's why you see very large vsize in 64bit even upon fresh start.

For b), we do have control on number of data and header files opened for reads/writes. But with only 30 data files (each 4MB), their vsize should be small (120MB).

Could you please help us capture TT's memory usage with pmap -x <id> before and after your query? FYI. My DB dir has 30 folder (1 per day) and each folder has 1 data, 1 header, and 1 index.

Thanks for your efforts to improve TickTockDB

jens-ylja commented 1 year ago

@ylin30 indeed my system has 8 cores (ARM Cortex-A15 (quad core) & ARM Cortex-A7 (quad core) in a big.LITTLE pack).

When running with defaults for http.listener.count and tcp.listener.count, ps -eLf gives me a NLWP of 77. When setting both of them to 8, ps -eLf gives me a NLWP of 78. In the latter setup pmap -X gives me a total vmem of 658572 and a rss of 4152.

When executing a query hitting all files pmap -X gives me a total vmem of 2909028 and rss of 9376 whereas almost all data.0 files have a vmem of 131072 each.

Attached please find the output of pmap -X -p for the newborn TT and after executing the query. Additionally please find the log written by TT and my configuration used. Regarding configuration - I stumbled around a little and reduced tsdb.page.count to reflect my small data file size. But this changed nothing. ticktock-1.zip

ylin30 commented 1 year ago

@ylin30 indeed my system has 8 cores (ARM Cortex-A15 (quad core) & ARM Cortex-A7 (quad core) in a big.LITTLE pack).

When running with defaults for http.listener.count and tcp.listener.count, ps -eLf gives me a NLWP of 77. When setting both of them to 8, ps -eLf gives me a NLWP of 78. In the latter setup pmap -X gives me a total vmem of 658572 and a rss of 4152.

When executing a query hitting all files pmap -X gives me a total vmem of 2909028 and rss of 9376 whereas almost all data.0 files have a vmem of 131072 each.

The direct cause is that there are 17 data.0 files opened and each uses 131072KB vsize. In total, they contribute 2.2GB vsize already.

What puzzled me is why each data file is so large, 131072KB? By default Its size should be (page_size page_count)=(128B 32768) = 4,194,304B. I verified that in Raspberry-PI-0 (ArmV6, 32bit OS, Raspbian GNU/Linux 11 (bullseye)).

I don't have Odroid HC1. But could you tell me what OS version you use?

At last, if you don't mind, you can replace line 610 in src/core/mmap.cpp to print out the file size.

        Logger::info("opening %s for read. length=%jd, page_size=%zu, page_count=%zu", m_name.c_str(), (intmax_t)length, m_page_size, m_page_count);

jens-ylja commented 1 year ago

@ylin30 My Odroid HC1 is running an Ubuntu 20.04 in a minimized server edition by Hardkernel (manufacturer of the Odroids).

$ uname -a
Linux gadab 5.4.227-248 #1 SMP PREEMPT Thu Dec 15 11:36:07 EST 2022 armv7l armv7l armv7l GNU/Linux

I'll replace the code line and come back with the new logs - hopefully soon :)

ylin30 commented 1 year ago

I found something fishy in your log.

2023-05-07 17:26:08.533 [INFO] [timer_task_0] closing data file /ticktock/ticktock-1/data/2023/4/1680652800.1680739200/data.0 (for both read & write), length = 20960870762807296

20960870762807296 looks like an overflow. Will check.

jens-ylja commented 1 year ago

Here is the new log file of the line 610 patched version: ticktock.zip And it's interesting.

@ylin30 you wrote about (page_size * page_count)=(128B * 32768) but my logs are page_size=4096, page_count=32768 whereas at start up the log contains a line stating mm::page-size = 128. But it contains too: sys-page-size = 4096.

ylin30 commented 1 year ago

I suspect it might be caused by compaction which compacts old data into new pages with a large page size (e.g., system page size 4kb). It doesn't matter in 64bit OS but has huge effect in 32bit OS. We will confirm if this is the cause.

Cheers

ylin30 commented 1 year ago

@jens-ylja This is confirmed to cause by compaction. Will be fixed in 0.11.8 soon. Thx!

Assigned to @ytyou.

jens-ylja commented 1 year ago

I just re-tested with the new v0.11.8 version and can confirm the issue to be fixed. Please find attached the current pmap output after executing the 90 days query on my ARMv7 32bit. pmap-ticktock-1-0.11.8-after.zip

Thanks a lot Jens

ylin30 commented 1 year ago

@jens-ylja only 571MB vsize after 90 days query on ArmV7 32bit! Good to see that works.

Again, thank you so much for discovering the bug. We wouldn't realize that if without you. Let TickTockDB rock!

ytyou / ticktock

TT returns inconsistent data on query #48