[0.10.0-nightly-146f36c] - Missing data a minute before current time. Comes back later

[gerrickw]

Summary:
It appears the first 10s tick after around a minute will have no data, while before and after showing data. If I wait a 10s-60s the data will show up, but the last minute will have no data. This could also be thought of.. data exists, data disappears around 1 minute mark, and comes back again. As a note I am only loading data in every 10 seconds with the same epoch time.

This actually use to be much worst on the dec 14th latest build where the duration of missing data was at times 1-5 minutes, but looks like it improved after I pulled the build today. Have only run for 30 minutes so a possibility it could get worst. Curious if it improved from #5142.

Log with build version:
2015/12/21 14:21:56 InfluxDB starting, version 0.10.0-nightly-146f36c, branch master, commit 146f36c,
built 2015-12-21T05:00:47+0000
2015/12/21 14:21:56 Go version go1.5.2, GOMAXPROCS set to 40

Pre-testing:

• Wiped all data
• Set config to use tsm1
• Config is default otherwise.

Data input repo steps:

• For feeding data used similar steps as: [0.9.3-rc1] Data disappears, replaced with a single point every 9 to 20 minutes #3781 (comment)
• pip install influxdb
• python simple_influx_writer.py
• User/pass/db are defaulted to test_db against localhost, but you can set as desired. Use "--help" to see the options. Can also limit the number of metrics with "--hhh_iii" etc.
• Script: https://gist.github.com/gerrickw/f83fb4d4d69aef2dfd37
• Query in 10 minutes after loading data: SELECT mean(value) FROM "e" WHERE "colo" = 'coloa' AND "pool" = 'hhh_iii' AND time > now() - 30m GROUP BY time(10s), "y" fill(null)
• Execute the same query in a minute and notice there is still a gap, but previous missing data exists.

Example images below showing issue. Notice how there is missing data around a minute with data before and after. Then on the 2nd screen shot notice the time range has progressed with previous data missing existing.

A few log entries related to compaction if useful:
[tsm1] 2015/12/21 14:44:15 compacted 3 TSM into 1 files in 3m7.324218109s
[tsm1] 2015/12/21 14:44:15 beginning compaction of 9 TSM files
[tsm1] 2015/12/21 14:45:22 compacted 9 TSM into 1 files in 1m6.612098711s
[tsm1] 2015/12/21 14:45:22 beginning compaction of 3 TSM files
[tsm1] 2015/12/21 14:46:11 compacted 3 TSM into 1 files in 49.335513717s
[tsm1] 2015/12/21 14:46:19 beginning compaction of 3 TSM files
[tsm1] 2015/12/21 14:46:49 compacted 3 TSM into 1 files in 30.000324717s
[tsm1] 2015/12/21 14:47:08 beginning compaction of 3 TSM files
[tsm1] 2015/12/21 14:47:40 compacted 3 TSM into 1 files in 32.406410161s
[tsm1] 2015/12/21 14:47:57 beginning compaction of 3 TSM files

[gravaton]

I'm also seeing "missing data" issues occasionally with TSM1 although it seems to happen under load as well. Let me know if there's any useful debug data I can provide to help troubleshoot

[gerrickw]

In this case the data exists, but reporting null. If you wait an extra period of time then the data will show up. It might be in some other processing state that the query object can not access.

As a note in grafana I am using report null as zero. So those dips in the graph are actually no data being returned by influxdb. I could print the response from influxdb, but found it easier to understand the problem with a graph.

[otoolep]

Thanks for the reports.

This is probably something to do with WAL caching -- data that still exists in the WAL must be combined with data on disk in TSM files. There may be some bugs in that area.

Once the data has been written completely to TSM files, it seems your data then looks good.

[otoolep]

cc @jwilder @pauldix

[gerrickw]

Noticed there were a few commits related to compaction and thought I'd mention this problem still exists with the latest version. This problem wouldn't be as bad if it was no data at the beginning as could blame it on being slow, but with a sudden loss of data it makes it appear something happened after a minute to users.

[jwilder]

@gerrickw Thanks for the update. Still looking into this issue.

[gerrickw]

No longer seeing a gap after building the latest version from master. Thanks! I tried downloading the nightly build today expecting to see the changes from yesterday, but the build referenced a commit from 4 days ago. Possibly a delay in making the latest builds.